[PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Thomas Richter]

perf test case 58 (record+probe_libc_inet_pton.sh)
executed on s390x using kernel 4.16.0rc3
displays this result:
 # ./perf trace --no-syscalls
           -e probe_libc:inet_pton/call-graph=dwarf/ ping -6 -c 1 ::1
     probe_libc:inet_pton: (3ffa0240448)
	      __GI___inet_pton (/usr/lib64/libc-2.26.so)
	      gaih_inet (inlined)
	      __GI_getaddrinfo (inlined)
	      main (/usr/bin/ping)
	      __libc_start_main (/usr/lib64/libc-2.26.so)
	     _start (/usr/bin/ping)

After I installed kernel 4.16.0 the same tests uses
commands
 # perf record -e probe_libc:inet_pton/call-graph=dwarf/
      -o /tmp/perf.data.abc ping -6 -c 1 ::1
 # perf script -i /tmp/perf.data.abc
and displays:
 ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
	       140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
	       fbde1 gaih_inet (inlined)
	       fe2b9 __GI_getaddrinfo (inlined)
	        398d main (/usr/bin/ping)

Nothing else changed including glibc elfutils and other libraries
picked up by the build.
The entries for __libc_start_main and _start are missing.

I bisected missing __libc_start_main and _start to commit
3d20c6246690219881786de10d2dda93f616d0ac
("perf unwind: Unwind with libdw doesn't take symfs into account")

When I undo this commit I get this call stack on s390:
 [root@s35lp76 perf]# ./perf script  -i /tmp/perf.data.abc
 ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
	140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
	 fbde1 gaih_inet (inlined)
	 fe2b9 __GI_getaddrinfo (inlined)
	  398d main (/usr/bin/ping)
	 22fbd __libc_start_main (/usr/lib64/libc-2.26.so)
	  457b _start (/usr/bin/ping)

Looks like dwarf functions dwfl_xxx  create different call back
stack trace when using file
/usr/lib/debug/usr/bin/ping-20161105-7.fc27.s390x.debug instead of
file /usr/bin/ping.

Fix this test case on s390 and do not expect any call back stack
entry after the main() function. Also be more robust and accept a
leading __GI_ prefix in front of getaddrinfo.

On x86 this test case shows the same call stack using
both kernel versions 4.16.0rc3 and 4.16.0 and also
stops at main:

[root@f27 perf]# ./perf script -i /tmp/perf.data.tmr
ping  4446 [000]   172.027088: probe_libc:inet_pton: (7fdfa08c93c0)
	           1393c0 __GI___inet_pton (/usr/lib64/libc-2.26.so)
	            fe60d getaddrinfo (/usr/lib64/libc-2.26.so)
	             2f40 main (/usr/bin/ping)

[root@f27 perf]#

Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
Reviewed-by: Hendrik Brueckner <brueckner@linux.ibm.com>
---
 tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 6 ++----
 1 file changed, 2 insertions(+), 4 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 1ecc1f0ff84a..016882dbbc16 100755
--- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
+++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
@@ -19,12 +19,10 @@ trace_libc_inet_pton_backtrace() {
 	expected[1]=".*inet_pton[[:space:]]\($libc\)$"
 	case "$(uname -m)" in
 	s390x)
-		eventattr='call-graph=dwarf'
+		eventattr='call-graph=dwarf,max-stack=4'
 		expected[2]="gaih_inet.*[[:space:]]\($libc|inlined\)$"
-		expected[3]="__GI_getaddrinfo[[:space:]]\($libc|inlined\)$"
+		expected[3]="(__GI_)?getaddrinfo[[:space:]]\($libc|inlined\)$"
 		expected[4]="main[[:space:]]\(.*/bin/ping.*\)$"
-		expected[5]="__libc_start_main[[:space:]]\($libc\)$"
-		expected[6]="_start[[:space:]]\(.*/bin/ping.*\)$"
 		;;
 	*)
 		eventattr='max-stack=3'
-- 
2.14.3

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Arnaldo Carvalho de Melo]

Em Thu, Apr 12, 2018 at 10:19:59AM +0200, Thomas Richter escreveu:
> perf test case 58 (record+probe_libc_inet_pton.sh)
> executed on s390x using kernel 4.16.0rc3
> displays this result:
>  # ./perf trace --no-syscalls
>            -e probe_libc:inet_pton/call-graph=dwarf/ ping -6 -c 1 ::1
>      probe_libc:inet_pton: (3ffa0240448)
> 	      __GI___inet_pton (/usr/lib64/libc-2.26.so)
> 	      gaih_inet (inlined)
> 	      __GI_getaddrinfo (inlined)
> 	      main (/usr/bin/ping)
> 	      __libc_start_main (/usr/lib64/libc-2.26.so)
> 	     _start (/usr/bin/ping)
> 
> After I installed kernel 4.16.0 the same tests uses
> commands
>  # perf record -e probe_libc:inet_pton/call-graph=dwarf/
>       -o /tmp/perf.data.abc ping -6 -c 1 ::1
>  # perf script -i /tmp/perf.data.abc
> and displays:
>  ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
> 	       140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
> 	       fbde1 gaih_inet (inlined)
> 	       fe2b9 __GI_getaddrinfo (inlined)
> 	        398d main (/usr/bin/ping)
> 
> Nothing else changed including glibc elfutils and other libraries
> picked up by the build.
> The entries for __libc_start_main and _start are missing.
> 
> I bisected missing __libc_start_main and _start to commit
> 3d20c6246690219881786de10d2dda93f616d0ac
> ("perf unwind: Unwind with libdw doesn't take symfs into account")

You forgot to add the author of that changeset to the CC list. Doing so
will give him the chance to look at this unintended consequence of his
work and maybe allow him to comment on your fix or provide an
alternative solution.

I've added him to the CC list now, Martin, can you please comment on
this?

- Arnaldo

> When I undo this commit I get this call stack on s390:
>  [root@s35lp76 perf]# ./perf script  -i /tmp/perf.data.abc
>  ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
> 	140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
> 	 fbde1 gaih_inet (inlined)
> 	 fe2b9 __GI_getaddrinfo (inlined)
> 	  398d main (/usr/bin/ping)
> 	 22fbd __libc_start_main (/usr/lib64/libc-2.26.so)
> 	  457b _start (/usr/bin/ping)
> 
> Looks like dwarf functions dwfl_xxx  create different call back
> stack trace when using file
> /usr/lib/debug/usr/bin/ping-20161105-7.fc27.s390x.debug instead of
> file /usr/bin/ping.
> 
> Fix this test case on s390 and do not expect any call back stack
> entry after the main() function. Also be more robust and accept a
> leading __GI_ prefix in front of getaddrinfo.
> 
> On x86 this test case shows the same call stack using
> both kernel versions 4.16.0rc3 and 4.16.0 and also
> stops at main:
> 
> [root@f27 perf]# ./perf script -i /tmp/perf.data.tmr
> ping  4446 [000]   172.027088: probe_libc:inet_pton: (7fdfa08c93c0)
> 	           1393c0 __GI___inet_pton (/usr/lib64/libc-2.26.so)
> 	            fe60d getaddrinfo (/usr/lib64/libc-2.26.so)
> 	             2f40 main (/usr/bin/ping)
> 
> [root@f27 perf]#
> 
> Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
> Reviewed-by: Hendrik Brueckner <brueckner@linux.ibm.com>
> ---
>  tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 6 ++----
>  1 file changed, 2 insertions(+), 4 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 1ecc1f0ff84a..016882dbbc16 100755
> --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
> @@ -19,12 +19,10 @@ trace_libc_inet_pton_backtrace() {
>  	expected[1]=".*inet_pton[[:space:]]\($libc\)$"
>  	case "$(uname -m)" in
>  	s390x)
> -		eventattr='call-graph=dwarf'
> +		eventattr='call-graph=dwarf,max-stack=4'
>  		expected[2]="gaih_inet.*[[:space:]]\($libc|inlined\)$"
> -		expected[3]="__GI_getaddrinfo[[:space:]]\($libc|inlined\)$"
> +		expected[3]="(__GI_)?getaddrinfo[[:space:]]\($libc|inlined\)$"
>  		expected[4]="main[[:space:]]\(.*/bin/ping.*\)$"
> -		expected[5]="__libc_start_main[[:space:]]\($libc\)$"
> -		expected[6]="_start[[:space:]]\(.*/bin/ping.*\)$"
>  		;;
>  	*)
>  		eventattr='max-stack=3'
> -- 
> 2.14.3

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Martin Vuille]

Apologies for any problems my patch may be causing.

I'm unclear on what is the proposed fix, other than reverting the commit.

In the problem scenario, is a --symfs option used? Is the debug info being obtained from the symfs directory?

Unfortunately, I've had to change my focus for the time being, so won't be able to investigate further for a while.

Arnaldo, I'm fine with you reverting this change for now.

Regards,

MV


On 04/12/18 09:10, Arnaldo Carvalho de Melo wrote:
> Em Thu, Apr 12, 2018 at 10:19:59AM +0200, Thomas Richter escreveu:
>> perf test case 58 (record+probe_libc_inet_pton.sh)
>> executed on s390x using kernel 4.16.0rc3
>> displays this result:
>>   # ./perf trace --no-syscalls
>>             -e probe_libc:inet_pton/call-graph=dwarf/ ping -6 -c 1 ::1
>>       probe_libc:inet_pton: (3ffa0240448)
>> 	      __GI___inet_pton (/usr/lib64/libc-2.26.so)
>> 	      gaih_inet (inlined)
>> 	      __GI_getaddrinfo (inlined)
>> 	      main (/usr/bin/ping)
>> 	      __libc_start_main (/usr/lib64/libc-2.26.so)
>> 	     _start (/usr/bin/ping)
>>
>> After I installed kernel 4.16.0 the same tests uses
>> commands
>>   # perf record -e probe_libc:inet_pton/call-graph=dwarf/
>>        -o /tmp/perf.data.abc ping -6 -c 1 ::1
>>   # perf script -i /tmp/perf.data.abc
>> and displays:
>>   ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
>> 	       140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
>> 	       fbde1 gaih_inet (inlined)
>> 	       fe2b9 __GI_getaddrinfo (inlined)
>> 	        398d main (/usr/bin/ping)
>>
>> Nothing else changed including glibc elfutils and other libraries
>> picked up by the build.
>> The entries for __libc_start_main and _start are missing.
>>
>> I bisected missing __libc_start_main and _start to commit
>> 3d20c6246690219881786de10d2dda93f616d0ac
>> ("perf unwind: Unwind with libdw doesn't take symfs into account")
> You forgot to add the author of that changeset to the CC list. Doing so
> will give him the chance to look at this unintended consequence of his
> work and maybe allow him to comment on your fix or provide an
> alternative solution.
>
> I've added him to the CC list now, Martin, can you please comment on
> this?
>
> - Arnaldo
>
>> When I undo this commit I get this call stack on s390:
>>   [root@s35lp76 perf]# ./perf script  -i /tmp/perf.data.abc
>>   ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448)
>> 	140448 __GI___inet_pton (/usr/lib64/libc-2.26.so)
>> 	 fbde1 gaih_inet (inlined)
>> 	 fe2b9 __GI_getaddrinfo (inlined)
>> 	  398d main (/usr/bin/ping)
>> 	 22fbd __libc_start_main (/usr/lib64/libc-2.26.so)
>> 	  457b _start (/usr/bin/ping)
>>
>> Looks like dwarf functions dwfl_xxx  create different call back
>> stack trace when using file
>> /usr/lib/debug/usr/bin/ping-20161105-7.fc27.s390x.debug instead of
>> file /usr/bin/ping.
>>
>> Fix this test case on s390 and do not expect any call back stack
>> entry after the main() function. Also be more robust and accept a
>> leading __GI_ prefix in front of getaddrinfo.
>>
>> On x86 this test case shows the same call stack using
>> both kernel versions 4.16.0rc3 and 4.16.0 and also
>> stops at main:
>>
>> [root@f27 perf]# ./perf script -i /tmp/perf.data.tmr
>> ping  4446 [000]   172.027088: probe_libc:inet_pton: (7fdfa08c93c0)
>> 	           1393c0 __GI___inet_pton (/usr/lib64/libc-2.26.so)
>> 	            fe60d getaddrinfo (/usr/lib64/libc-2.26.so)
>> 	             2f40 main (/usr/bin/ping)
>>
>> [root@f27 perf]#
>>
>> Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
>> Reviewed-by: Hendrik Brueckner <brueckner@linux.ibm.com>
>> ---
>>   tools/perf/tests/shell/record+probe_libc_inet_pton.sh | 6 ++----
>>   1 file changed, 2 insertions(+), 4 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 1ecc1f0ff84a..016882dbbc16 100755
>> --- a/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
>> +++ b/tools/perf/tests/shell/record+probe_libc_inet_pton.sh
>> @@ -19,12 +19,10 @@ trace_libc_inet_pton_backtrace() {
>>   	expected[1]=".*inet_pton[[:space:]]\($libc\)$"
>>   	case "$(uname -m)" in
>>   	s390x)
>> -		eventattr='call-graph=dwarf'
>> +		eventattr='call-graph=dwarf,max-stack=4'
>>   		expected[2]="gaih_inet.*[[:space:]]\($libc|inlined\)$"
>> -		expected[3]="__GI_getaddrinfo[[:space:]]\($libc|inlined\)$"
>> +		expected[3]="(__GI_)?getaddrinfo[[:space:]]\($libc|inlined\)$"
>>   		expected[4]="main[[:space:]]\(.*/bin/ping.*\)$"
>> -		expected[5]="__libc_start_main[[:space:]]\($libc\)$"
>> -		expected[6]="_start[[:space:]]\(.*/bin/ping.*\)$"
>>   		;;
>>   	*)
>>   		eventattr='max-stack=3'
>> -- 
>> 2.14.3

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Thomas-Mich Richter]

On 04/25/2018 04:19 PM, Martin Vuille wrote:
> Apologies for any problems my patch may be causing.
> 
> I'm unclear on what is the proposed fix, other than reverting the commit.
> 
> In the problem scenario, is a --symfs option used? Is the debug info being obtained from the symfs directory?
> 
> Unfortunately, I've had to change my focus for the time being, so won't be able to investigate further for a while.
> 
> Arnaldo, I'm fine with you reverting this change for now.
> 
> Regards,
> 
> MV
> 
> 

Martin,

there is no need to revert the patch. I have adopted the test case for s390 and it
now stops at main, which is identical to x86.

The --symfs option was not used, however the debug file selected for dwarf examination
was different. With you patch it changed from /usr/lib64/libc.so (old) to
/usr/lib/debug/lib64/libc-2.26.so.debug (new)
and I think that this file has not all the info (at least on s390).

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

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Martin Vuille]

On 04/26/18 04:09, Thomas-Mich Richter wrote:
>
> Martin,
>
> there is no need to revert the patch. I have adopted the test case for s390 and it
> now stops at main, which is identical to x86.
>
> The --symfs option was not used, however the debug file selected for dwarf examination
> was different. With you patch it changed from /usr/lib64/libc.so (old) to
> /usr/lib/debug/lib64/libc-2.26.so.debug (new)
> and I think that this file has not all the info (at least on s390).
>
Thomas,

Thanks for the additional information. My change was intended to only affect
the case where a --symfs option is used, so your finding is surprising.

I'll take a look to see why this is happening.

Regards,
MV

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Martin Vuille]

On 04/26/18 04:09, Thomas-Mich Richter wrote:
> was different. With you patch it changed from /usr/lib64/libc.so (old) to
> /usr/lib/debug/lib64/libc-2.26.so.debug (new)
>
Thomas,

Can you tell me what 'file' reports for the old and new files?

Regards,
MV

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Thomas-Mich Richter]

On 04/26/2018 05:26 PM, Martin Vuille wrote:
> 
> 
> On 04/26/18 04:09, Thomas-Mich Richter wrote:
>> was different. With you patch it changed from /usr/lib64/libc.so (old) to
>> /usr/lib/debug/lib64/libc-2.26.so.debug (new)
>>
> Thomas,
> 
> Can you tell me what 'file' reports for the old and new files?
> 
> Regards,
> MV
> 

Martin,

not sure I understand your question:

Before your patch the file which was picked by dwarf was
/usr/lib64/libc.so

With your patch file which was picked by dwarf was 
/usr/lib/debug/lib64/libc-2.26.so.debug

Was this your question?
-- 
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

Re: [PATCH] perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

[Martin Vuille]

On 04/27/18 03:55, Thomas-Mich Richter wrote:
> On 04/26/2018 05:26 PM, Martin Vuille wrote:
>>
>> On 04/26/18 04:09, Thomas-Mich Richter wrote:
>>> was different. With you patch it changed from /usr/lib64/libc.so (old) to
>>> /usr/lib/debug/lib64/libc-2.26.so.debug (new)
>>>
>> Thomas,
>>
>> Can you tell me what 'file' reports for the old and new files?
>>
>> Regards,
>> MV
>>
> Martin,
>
> not sure I understand your question:
>
> Before your patch the file which was picked by dwarf was
> /usr/lib64/libc.so
>
>
> With your patch file which was picked by dwarf was
> /usr/lib/debug/lib64/libc-2.26.so.debug
>
> Was this your question?
Thomas,

Apologies for being unclear in my request.

I was asking what the commands "file /usr/lib64/libc.so"
and "file /usr/lib/debug/lib64/libc-2.26.so.debug" report.

MV