Re: [PATCH] perf tests: Fix regex for record+probe_libc_inet_pton.sh

From: Arnaldo Carvalho de Melo
Date: Fri May 18 2018 - 14:33:14 EST


Em Fri, May 18, 2018 at 04:21:02PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, May 18, 2018 at 12:54:17PM +0530, Sandipan Das escreveu:
> > This test currently fails because the regular expressions for
> > matching the output of perf script do not consider the symbol
> > offsets to be part of the output.
> >
> > The symbol offsets are seen because of the default behaviour
> > introduced by commit 4140d2ea74b3 ("perf script: Show symbol
> > offsets by default").
> >
> > Before applying this patch:
> >
> > # perf test -v "probe libc's inet_pton & backtrace it with ping"
> >
> > 62: probe libc's inet_pton & backtrace it with ping :
> > --- start ---
> > test child forked, pid 30389
> > ping 30406 [002] 307144.280983: probe_libc:inet_pton: (7f4117adf220)
> > 7f4117adf220 __GI___inet_pton+0x0 (/usr/lib64/libc-2.25.so)
> > FAIL: expected backtrace entry 1 ".*inet_pton[[:space:]]\(/usr/lib64/libc-2.25.so|inlined\)$" got "7f4117adf220 __GI___inet_pton+0x0 (/usr/lib64/libc-2.25.so)"
> > test child finished with -1
> > ---- end ----
> > probe libc's inet_pton & backtrace it with ping: FAILED!
> >
> > After applying this patch:
> >
> > # perf test -v "probe libc's inet_pton & backtrace it with ping"
> >
> > 62: probe libc's inet_pton & backtrace it with ping :
> > --- start ---
> > test child forked, pid 30539
> > ping 30556 [003] 307254.313217: probe_libc:inet_pton: (7fe19ab10220)
> > 7fe19ab10220 __GI___inet_pton+0x0 (/usr/lib64/libc-2.25.so)
> > 7fe19aad5ebd getaddrinfo+0x11d (/usr/lib64/libc-2.25.so)
> > 56351e3c1c71 main+0x891 (/usr/bin/ping)
> > test child finished with 0
> > ---- end ----
> > probe libc's inet_pton & backtrace it with ping: Ok
>
> Here it went from failing with:
>
> [root@seventh ~]# perf test -v pton
> 64: probe libc's inet_pton & backtrace it with ping :
> --- start ---
> test child forked, pid 22590
> ping 22607 [001] 12782.425689: probe_libc:inet_pton: (7f8686da4e40)
> 7f8686da4e40 __GI___inet_pton+0x0 (/usr/lib64/libc-2.26.so)
> FAIL: expected backtrace entry 1 ".*inet_pton[[:space:]]\(/usr/lib64/libc-2.26.so|inlined\)$" got "7f8686da4e40 __GI___inet_pton+0x0 (/usr/lib64/libc-2.26.so)"
> test child finished with -1
> ---- end ----
> probe libc's inet_pton & backtrace it with ping: FAILED!
> [root@seventh ~]#
>
> To failing with:
>
> [root@seventh ~]# perf test -v pton
> 64: probe libc's inet_pton & backtrace it with ping :
> --- start ---
> test child forked, pid 28954
> ping 28971 [002] 14277.711200: probe_libc:inet_pton: (7fc9d66e3e40)
> 7fc9d66e3e40 __GI___inet_pton+0x0 (/usr/lib64/libc-2.26.so)
> 7fc9d66b02b4 getaddrinfo+0x124 (/usr/lib64/libc-2.26.so)
> 56075cb98f40 [unknown] (/usr/bin/ping)
> FAIL: expected backtrace entry 3 ".*\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$" got "56075cb98f40 [unknown] (/usr/bin/ping)"
> test child finished with -1
> ---- end ----
> probe libc's inet_pton & backtrace it with ping: FAILED!
> [root@seventh ~]#
>
> Trying to figure this out...

[root@seventh perf]# perf script
ping 29170 [001] 14644.810782: probe_libc:inet_pton: (7f0bac71be40)
7f0bac71be40 __GI___inet_pton+0x0 (/usr/lib64/libc-2.26.so)
7f0bac6e82b4 getaddrinfo+0x124 (/usr/lib64/libc-2.26.so)
5585e10adf40 [unknown] (/usr/bin/ping)

[root@seventh perf]# perf report --mmaps
# pid tid ppid comm
0 0 -1 |swapper
29170 29170 -1 |ping
5585e10ab000-5585e12dd000 r-xp 00000000 2771393 /usr/bin/ping
7f0babfcf000-7f0bac1ed000 r-xp 00000000 2762913 /usr/lib64/libpthread-2.26.so
7f0bac1ed000-7f0bac3f1000 r-xp 00000000 2753363 /usr/lib64/libdl-2.26.so
7f0bac3f1000-7f0bac608000 r-xp 00000000 2760078 /usr/lib64/libz.so.1.2.11
7f0bac608000-7f0bac9be000 r-xp 00000000 2753359 /usr/lib64/libc-2.26.so
7f0bac9be000-7f0bacd09000 r-xp 00000000 2762901 /usr/lib64/libm-2.26.so
7f0bacd09000-7f0bacf20000 r-xp 00000000 2762915 /usr/lib64/libresolv-2.26.so
7f0bacf20000-7f0bad3a8000 r-xp 00000000 2764213 /usr/lib64/libcrypto.so.1.1.0h
7f0bad3a8000-7f0bad5dc000 r-xp 00000000 2761070 /usr/lib64/libidn.so.11.6.18
7f0bad5dc000-7f0bad7e1000 r-xp 00000000 2760189 /usr/lib64/libcap.so.2.25
7f0bad7e1000-7f0bada08000 r-xp 00000000 2753353 /usr/lib64/ld-2.26.so
7ffe23d99000-7ffe23d9b000 r-xp 00000000 0 [vdso]
[root@seventh perf]#

So it is there, but I don't have debuginfo for ping, lets see if I add
it...

[root@seventh perf]# rpm -qf `which ping`
iputils-20161105-7.fc27.x86_64
[root@seventh perf]#
[root@seventh perf]# dnf debuginfo-install iputils

[root@seventh perf]# perf script
ping 29170 [001] 14644.810782: probe_libc:inet_pton: (7f0bac71be40)
7f0bac71be40 __GI___inet_pton+0x0 (/usr/lib64/libc-2.26.so)
7f0bac6e82b4 getaddrinfo+0x124 (/usr/lib64/libc-2.26.so)
5585e10adf40 main+0x880 (/usr/bin/ping)

[root@seventh perf]#

So we need to check if debuginfo is available, and if so, expect it to
resolve that entry to main, if not, expect it to _not_ resolve and have
[unknown] instead...

- Arnaldo