2018-05-18 07:25:01

by Sandipan Das

[permalink] [raw]
Subject: [PATCH] perf tests: Fix regex for record+probe_libc_inet_pton.sh

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

Signed-off-by: Sandipan Das <[email protected]>
---
tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 12 ++++++------
1 file changed, 6 insertions(+), 6 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 ee86473643be..650b208f700f 100755
--- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
+++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
@@ -16,18 +16,18 @@ nm -g $libc 2>/dev/null | fgrep -q inet_pton || exit 254
trace_libc_inet_pton_backtrace() {
idx=0
expected[0]="ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\)"
- expected[1]=".*inet_pton[[:space:]]\($libc|inlined\)$"
+ expected[1]=".*inet_pton\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
case "$(uname -m)" in
s390x)
eventattr='call-graph=dwarf,max-stack=4'
- expected[2]="gaih_inet.*[[:space:]]\($libc|inlined\)$"
- expected[3]="(__GI_)?getaddrinfo[[:space:]]\($libc|inlined\)$"
- expected[4]="main[[:space:]]\(.*/bin/ping.*\)$"
+ expected[2]="gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
+ expected[3]="(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
+ expected[4]="main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$"
;;
*)
eventattr='max-stack=3'
- expected[2]="getaddrinfo[[:space:]]\($libc\)$"
- expected[3]=".*\(.*/bin/ping.*\)$"
+ expected[2]="getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$"
+ expected[3]=".*\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$"
;;
esac

--
2.13.6



2018-05-18 10:21:42

by Thomas Richter

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

On 05/18/2018 09:24 AM, Sandipan Das wrote:
> 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
>
> Signed-off-by: Sandipan Das <[email protected]>
> ---
> tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 12 ++++++------
> 1 file changed, 6 insertions(+), 6 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 ee86473643be..650b208f700f 100755
> --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> @@ -16,18 +16,18 @@ nm -g $libc 2>/dev/null | fgrep -q inet_pton || exit 254
> trace_libc_inet_pton_backtrace() {
> idx=0
> expected[0]="ping[][0-9 \.:]+probe_libc:inet_pton: \([[:xdigit:]]+\)"
> - expected[1]=".*inet_pton[[:space:]]\($libc|inlined\)$"
> + expected[1]=".*inet_pton\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
> case "$(uname -m)" in
> s390x)
> eventattr='call-graph=dwarf,max-stack=4'
> - expected[2]="gaih_inet.*[[:space:]]\($libc|inlined\)$"
> - expected[3]="(__GI_)?getaddrinfo[[:space:]]\($libc|inlined\)$"
> - expected[4]="main[[:space:]]\(.*/bin/ping.*\)$"
> + expected[2]="gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
> + expected[3]="(__GI_)?getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc|inlined\)$"
> + expected[4]="main\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$"
> ;;
> *)
> eventattr='max-stack=3'
> - expected[2]="getaddrinfo[[:space:]]\($libc\)$"
> - expected[3]=".*\(.*/bin/ping.*\)$"
> + expected[2]="getaddrinfo\+0x[[:xdigit:]]+[[:space:]]\($libc\)$"
> + expected[3]=".*\+0x[[:xdigit:]]+[[:space:]]\(.*/bin/ping.*\)$"
> ;;
> esac
>
>

This patch fails on s390. I used 4.17.0rc5 + fedora 27 and I get this output:


[root@p23lp27 perf]# ./perf test 59
59: probe libc's inet_pton & backtrace it with ping : Ok
[root@p23lp27 linux]# cd ~/linux; patch -p1 < ../inet_pton1
(Stripping trailing CRs from patch; use --binary to disable.)
patching file tools/perf/tests/shell/record+probe_libc_inet_pton.sh
[root@p23lp27 linux]# cd -;
[root@p23lp27 perf]# ./perf test 59
59: probe libc's inet_pton & backtrace it with ping : FAILED!
[root@p23lp27 perf]#

Debugging revealed this line as cause of failure:


FAIL: expected backtrace entry 2 "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc-2.26.so|inlined\)$" got "fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)"

Here is the output of the trace file

[root@p23lp27 perf]# perf script
ping 87291 [001] 96936.231618: probe_libc:inet_pton: (3ff96342378)
142378 __inet_pton (inlined)
fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
100189 __GI_getaddrinfo (inlined)
398d main (/usr/bin/ping)
2303d __libc_start_main (/usr/lib64/libc-2.26.so)
457b [unknown] (/usr/bin/ping)

[root@p23lp27 perf]#

Hope this helps
--
Thomas Richter, Dept 3303, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


2018-05-18 10:30:07

by Sandipan Das

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

Hi Thomas,

On 05/18/2018 03:51 PM, Thomas-Mich Richter wrote:
[...]
>
> This patch fails on s390. I used 4.17.0rc5 + fedora 27 and I get this output:
>
>
> [root@p23lp27 perf]# ./perf test 59
> 59: probe libc's inet_pton & backtrace it with ping : Ok
> [root@p23lp27 linux]# cd ~/linux; patch -p1 < ../inet_pton1
> (Stripping trailing CRs from patch; use --binary to disable.)
> patching file tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> [root@p23lp27 linux]# cd -;
> [root@p23lp27 perf]# ./perf test 59
> 59: probe libc's inet_pton & backtrace it with ping : FAILED!
> [root@p23lp27 perf]#
>
> Debugging revealed this line as cause of failure:
>
>
> FAIL: expected backtrace entry 2 "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc-2.26.so|inlined\)$" got "fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)"
>
> Here is the output of the trace file
>
> [root@p23lp27 perf]# perf script
> ping 87291 [001] 96936.231618: probe_libc:inet_pton: (3ff96342378)
> 142378 __inet_pton (inlined)
> fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
> 100189 __GI_getaddrinfo (inlined)
> 398d main (/usr/bin/ping)
> 2303d __libc_start_main (/usr/lib64/libc-2.26.so)
> 457b [unknown] (/usr/bin/ping)
>
> [root@p23lp27 perf]#
>
> Hope this helps
>

Can you please apply these two patches as well and then re-test?

[1] https://lkml.org/lkml/2018/5/17/112
[2] https://lkml.org/lkml/2018/5/17/113

- Sandipan


2018-05-18 11:11:32

by Thomas Richter

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

On 05/18/2018 12:29 PM, Sandipan Das wrote:
> Hi Thomas,
>
> On 05/18/2018 03:51 PM, Thomas-Mich Richter wrote:
> [...]
>>
>> This patch fails on s390. I used 4.17.0rc5 + fedora 27 and I get this output:
>>
>>
>> [root@p23lp27 perf]# ./perf test 59
>> 59: probe libc's inet_pton & backtrace it with ping : Ok
>> [root@p23lp27 linux]# cd ~/linux; patch -p1 < ../inet_pton1
>> (Stripping trailing CRs from patch; use --binary to disable.)
>> patching file tools/perf/tests/shell/record+probe_libc_inet_pton.sh
>> [root@p23lp27 linux]# cd -;
>> [root@p23lp27 perf]# ./perf test 59
>> 59: probe libc's inet_pton & backtrace it with ping : FAILED!
>> [root@p23lp27 perf]#
>>
>> Debugging revealed this line as cause of failure:
>>
>>
>> FAIL: expected backtrace entry 2 "gaih_inet.*\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc-2.26.so|inlined\)$" got "fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)"
>>
>> Here is the output of the trace file
>>
>> [root@p23lp27 perf]# perf script
>> ping 87291 [001] 96936.231618: probe_libc:inet_pton: (3ff96342378)
>> 142378 __inet_pton (inlined)
>> fdcb1 gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
>> 100189 __GI_getaddrinfo (inlined)
>> 398d main (/usr/bin/ping)
>> 2303d __libc_start_main (/usr/lib64/libc-2.26.so)
>> 457b [unknown] (/usr/bin/ping)
>>
>> [root@p23lp27 perf]#
>>
>> Hope this helps
>>
>
> Can you please apply these two patches as well and then re-test?
>
> [1] https://lkml.org/lkml/2018/5/17/112
> [2] https://lkml.org/lkml/2018/5/17/113
>
> - Sandipan
>

Ahhh, yes that helped. Must have missed it. Thanks for the pointer.

--
Thomas Richter, Dept 3303, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


2018-05-18 14:17:04

by Arnaldo Carvalho de Melo

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

Em Fri, May 18, 2018 at 01:09:48PM +0200, Thomas-Mich Richter escreveu:
> On 05/18/2018 12:29 PM, Sandipan Das wrote:
> > Can you please apply these two patches as well and then re-test?

> > [1] https://lkml.org/lkml/2018/5/17/112
> > [2] https://lkml.org/lkml/2018/5/17/113

> Ahhh, yes that helped. Must have missed it. Thanks for the pointer.

Cool, can I take that as a Tested-by: Thomas?

- Arnaldo

2018-05-18 18:24:57

by Arnaldo Carvalho de Melo

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

Em Fri, May 18, 2018 at 11:14:45AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, May 18, 2018 at 01:09:48PM +0200, Thomas-Mich Richter escreveu:
> > On 05/18/2018 12:29 PM, Sandipan Das wrote:
> > > Can you please apply these two patches as well and then re-test?
>
> > > [1] https://lkml.org/lkml/2018/5/17/112
> > > [2] https://lkml.org/lkml/2018/5/17/113
>
> > Ahhh, yes that helped. Must have missed it. Thanks for the pointer.
>
> Cool, can I take that as a Tested-by: Thomas?

Actually I'll fold this patch into the patch that made this test break,
so that we keep the tree bisectable wrt that specific 'perf test' entry.

- Arnaldo

2018-05-18 19:21:40

by Arnaldo Carvalho de Melo

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

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...

- Arnaldo

2018-05-18 19:29:13

by Sandipan Das

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

Hi Arnaldo,

On 05/19/2018 12:51 AM, Arnaldo Carvalho de Melo wrote:
> 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...
>

Looks like perf failed to resolve the symbol's name for the last entry
in the callchain. I did not consider this case. So, if this happens, we
would be better off using the original regex for the last line:

expected[3]=".*\(.*/bin/ping.*\)$"

- Sandipan


2018-05-18 19:29:51

by Arnaldo Carvalho de Melo

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

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

2018-05-18 19:32:05

by Arnaldo Carvalho de Melo

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

Em Fri, May 18, 2018 at 04:29:16PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, May 18, 2018 at 04:21:02PM -0300, Arnaldo Carvalho de Melo escreveu:
> > 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...

But tis is not related to your recent patches, so I'm folding this last
one with the one adding the offsets and go on from there...

- Arnaldo

2018-05-22 06:14:55

by Thomas Richter

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

On 05/18/2018 04:14 PM, Arnaldo Carvalho de Melo wrote:
> Em Fri, May 18, 2018 at 01:09:48PM +0200, Thomas-Mich Richter escreveu:
>> On 05/18/2018 12:29 PM, Sandipan Das wrote:
>>> Can you please apply these two patches as well and then re-test?
>
>>> [1] https://lkml.org/lkml/2018/5/17/112
>>> [2] https://lkml.org/lkml/2018/5/17/113
>
>> Ahhh, yes that helped. Must have missed it. Thanks for the pointer.
>
> Cool, can I take that as a Tested-by: Thomas?
>
> - Arnaldo
>
Sure

--
Thomas Richter, Dept 3303, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


2018-07-04 07:03:28

by kernel test robot

[permalink] [raw]
Subject: [lkp-robot] [perf tests] 32a4debc7c: perf-sanity-tests.probe_libc's_inet_pton_&_backtrace_it_with_ping.fail


FYI, we noticed the following commit (built with gcc-7):

commit: 32a4debc7c89ee5e29c0bbdfdd3ae0ce0e01057f ("[PATCH] perf tests: Fix regex for record+probe_libc_inet_pton.sh")
url: https://github.com/0day-ci/linux/commits/Sandipan-Das/perf-tests-Fix-regex-for-record-probe_libc_inet_pton-sh/20180521-130408


in testcase: perf-sanity-tests
with following parameters:

perf_compiler: gcc



on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -smp 2 -m 8G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


2018-05-22 17:41:14 sudo /usr/src/linux-perf-x86_64-fedora-25-32a4debc7c89ee5e29c0bbdfdd3ae0ce0e01057f/tools/perf/perf test 62
62: probe libc's inet_pton & backtrace it with ping : FAILED!



To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Xiaolong


Attachments:
(No filename) (988.00 B)
job-script (4.39 kB)
dmesg.xz (20.34 kB)
perf-sanity-tests (24.75 kB)
Download all attachments

2018-07-04 12:39:55

by Sandipan Das

[permalink] [raw]
Subject: Re: [lkp-robot] [perf tests] 32a4debc7c: perf-sanity-tests.probe_libc's_inet_pton_&_backtrace_it_with_ping.fail

Hi Xiaolong,

On 07/04/2018 12:27 PM, kernel test robot wrote:
>
> FYI, we noticed the following commit (built with gcc-7):
>
> commit: 32a4debc7c89ee5e29c0bbdfdd3ae0ce0e01057f ("[PATCH] perf tests: Fix regex for record+probe_libc_inet_pton.sh")
> url: https://github.com/0day-ci/linux/commits/Sandipan-Das/perf-tests-Fix-regex-for-record-probe_libc_inet_pton-sh/20180521-130408
>
>
> in testcase: perf-sanity-tests
> with following parameters:
>
> perf_compiler: gcc
>
>
>
> on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -smp 2 -m 8G
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
> 2018-05-22 17:41:14 sudo /usr/src/linux-perf-x86_64-fedora-25-32a4debc7c89ee5e29c0bbdfdd3ae0ce0e01057f/tools/perf/perf test 62
> 62: probe libc's inet_pton & backtrace it with ping : FAILED!
>
>

This patch has the following dependencies which seem to be missing from your source tree.

7903a7086723 ("perf script: Show symbol offsets by default")
19610184693c ("perf script: Show virtual addresses instead of offsets")

Output without these patches:

62: probe libc's inet_pton & backtrace it with ping :
--- start ---
test child forked, pid 10323
ping 10340 [001] 888647.764907: probe_libc:inet_pton: (7fe66cbc2220)
132220 __GI___inet_pton (/usr/lib64/libc-2.25.so)
FAIL: expected backtrace entry 1 ".*inet_pton\+0x[[:xdigit:]]+[[:space:]]\(/usr/lib64/libc-2.25.so|inlined\)$" got "132220 __GI___inet_pton (/usr/lib64/libc-2.25.so)"
test child finished with -1
---- end ----
probe libc's inet_pton & backtrace it with ping: FAILED!


Output with these patches:

62: probe libc's inet_pton & backtrace it with ping :
--- start ---
test child forked, pid 13155
ping 13172 [000] 888783.582767: probe_libc:inet_pton: (7f2afe5ce220)
7f2afe5ce220 __GI___inet_pton+0x0 (/usr/lib64/libc-2.25.so)
7f2afe593ebd getaddrinfo+0x11d (/usr/lib64/libc-2.25.so)
55b725fd8c71 main+0x891 (/usr/bin/ping)
test child finished with 0
---- end ----
probe libc's inet_pton & backtrace it with ping: Ok


--
With Regards,
Sandipan