Re: perf test for inet_pton probe fails to match stacktrace

[Arnaldo Carvalho de Melo <acme@kernel.org>]

On Tue, Nov 26, 2024 at 10:27:05AM +0000, Leo Yan wrote:
> On Mon, Nov 25, 2024 at 09:08:15PM -0800, Namhyung Kim wrote:
> 
> [...]
> 
> > > Using nm $libc in both cases, and increasing max-stack to 4 allows the test to pass:
> > >
> > > $ sudo ./perf test -vF pton
> > > --- start ---
> > > ping 1237113 [000] 18561.204983: probe_libc:inet_pton: (7f7c34d38eb7)
> > > 7f7c34d38eb7 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
> > > 7f7c34d4b517 gaih_inet+0x112 (/usr/lib64/libc.so.6)
> > > 7f7c34d4cb73 getaddrinfo+0x133 (/usr/lib64/libc.so.6)
> > > 55680ac46518 [unknown] (/usr/bin/ping)
> > > ---- end ----
> > >  86: probe libc's inet_pton & backtrace it with ping                 : Ok
> > 
> > I think it's very fragile as it depends on specific entries in the call
> > stack.  As we want to test if perf probe (for uprobes) and perf record
> > working correctly, maybe it can just check the number of samples only.
> > 
> > Arnaldo, what do you think?
> 
> Though this question is asking Arnaldo, I have a different idea for
> fixing the test ;)
> 
> The middle entries in the callchain are varied on different archs and
> distro.  E.g. Guilherme reported back the '-D' option is not needed but
> at my side it is required on Arm64 machine with Ubuntu distro.
> 
> However, the three entries in the callchain are existed consistently:
> 
>   ping 1237113 [000] 18561.204983: probe_libc:inet_pton: (7f7c34d38eb7)
>   7f7c34d38eb7 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
>   ...
>   55680ac46518 [unknown] (/usr/bin/ping)
> 
> We can change the code to only matching these three entries.  The
> change is as below.  We can consolidate the code for all archs
> (I am not 100% sure for x390x so I leave it).
> 
> Please let me know if this makes sense for you?
> 
> Thanks,
> Leo

Seems to work:

Before, on a:

root@number:~# grep -m1 'model name' /proc/cpuinfo 
model name	: Intel(R) Core(TM) i7-14700K
root@number:~#

root@number:~# perf test -vF pton
--- start ---
ping 229025 [017] 34027.968348: probe_libc:inet_pton: (7fc4542c10d0)
7fc4542c10d0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
7fc4542d5a55 getaddrinfo+0xcf5 (/usr/lib64/libc.so.6)
FAIL: expected backtrace entry ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" got "7fc4542d5a55 getaddrinfo+0xcf5 (/usr/lib64/libc.so.6)"
---- end ----
 86: probe libc's inet_pton & backtrace it with ping                 : FAILED!
root@number:~# 

With your patch:

root@number:~# perf test -vF pton
--- start ---
pattern: ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\)
line: ping  231118 [023] 34089.948542: probe_libc:inet_pton: (7f635297f0d0)
found=0
pattern: .*inet_pton\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc.so.6|inlined\)$
line: ping  231118 [023] 34089.948542: probe_libc:inet_pton: (7f635297f0d0)
found=1
line: 7f635297f0d0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
found=0
pattern: .*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$
line: ping  231118 [023] 34089.948542: probe_libc:inet_pton: (7f635297f0d0)
found=1
line: 7f635297f0d0 __GI___inet_pton+0x0 (/usr/lib64/libc.so.6)
found=1
line: 7f6352993a55 getaddrinfo+0xcf5 (/usr/lib64/libc.so.6)
found=1
line: 55ae71919969 [unknown] (/usr/bin/ping)
found=0
---- end ----
 86: probe libc's inet_pton & backtrace it with ping                 : Ok
root@number:~#

Replace that "unfound" with "Didn't find the"

And using 'found' as a variable name that when zero means "Ok, found"
and when 1 (grep failed to find the regexp) means "Didn't find" looks
confusing.

General idea seems to make the test resilient to the differences while
still testing the backtrace in uprobes events for expected entries.

- Arnaldo
 
> ---8<---
> 
> 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 47a26f25db9f..6ef58aedf2d8 100755
> --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> @@ -43,17 +43,8 @@ trace_libc_inet_pton_backtrace() {
>  		echo "((__GI_)?getaddrinfo|text_to_binary_address)\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$" >> $expected
>  		echo "(gaih_inet|main)\+0x[[:xdigit:]]+[[:space:]]\(inlined|.*/bin/ping.*\)$" >> $expected
>  		;;
> -	ppc64|ppc64le)
> -		eventattr='max-stack=4'
> -		# Add gaih_inet to expected backtrace only if it is part of libc.
> -		if nm $libc | grep -F -q gaih_inet.; then
> -			echo "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected
> -		fi
> -		echo "getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$" >> $expected
> -		echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected
> -		;;
>  	*)
> -		eventattr='max-stack=3'
> +		eventattr='max-stack=4'
>  		echo ".*(\+0x[[:xdigit:]]+|\[unknown\])[[:space:]]\(.*/bin/ping.*\)$" >> $expected
>  		;;
>  	esac
> @@ -76,14 +67,23 @@ trace_libc_inet_pton_backtrace() {
>  	fi
>  	perf script -i $perf_data | tac | grep -m1 ^ping -B9 | tac > $perf_script
>  
> -	exec 3<$perf_script
>  	exec 4<$expected
> -	while read line <&3 && read -r pattern <&4; do
> +	while read -r pattern <&4; do
> +		echo "pattern: $pattern"
>  		[ -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"
> +
> +		exec 3<$perf_script
> +		while read line <&3; do
> +			[ -z "$line" ] && break
> +			echo "line: $line"
> +			echo "$line" | grep -E -q "$pattern"
> +			found=$?
> +			echo "found=$found"
> +			[ $found -eq 0 ] && break
> +		done
> +
> +		if [ $found -ne 0 ] ; then
> +			printf "FAIL: unfound the expected backtrace entry \"%s\"\n" "$pattern"
>  			return 1
>  		fi
>  	done