Fedora 33 and perf probe failures

Fedora 33 and perf probe failures

[Thomas Richter]

I debugged the failure of some perf test cases on Fedora 33. The following
test cases fail on s390 and x86_64 using

[root@f33 yum.repos.d]# uname -a
Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020
                                x86_64 x86_64 x86_64 GNU/Linux
[root@f33 yum.repos.d]#

[root@f33 yum.repos.d]# perf test -F 74 77 78
74: Use vfs_getname probe to get syscall args filenames
                :Failed to write event: Invalid argument
Error: Failed to add events.
FAILED!
77: Check open filename arg using perf trace + vfs_getname
                :Failed to write event: Invalid argument
Error: Failed to add events.
FAILED!
78: Add vfs_getname probe to get syscall args filenames
                :Failed to write event: Invalid argument
Error: Failed to add events.
FAILED!
[root@f33 yum.repos.d]#

The root cause is the output of perf probe -L which returns:
[root@f33 yum.repos.d]# perf probe -L getname_flags
Specified source line is not found.
Error: Failed to show lines.
[root@f33 yum.repos.d]#

whereas on my Fedora 32 installation this command shows
[root@t35lp46 perf]# cat /etc/redhat-release
Fedora release 32 (Thirty Two)
[root@t35lp46 perf]#

[root@t35lp46 perf]# ./perf probe -L getname_flags | tail -10
     68                         return ERR_PTR(-ENOENT);
                        }
                }

     72         result->uptr = filename;
     73         result->aname = NULL;
     74         audit_getname(result);
                return result;
}

[root@t35lp46 perf]#

Any ideas how to fix this? Is this failure related to a missing debuginfod
setup, even when I have installed the debuginfo packages for the kernel:

[root@f33 ~]# perf probe -L getname_flags
Specified source line is not found.
  Error: Failed to show lines.
[root@f33 ~]# uname -a
Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
[root@f33 ~]# rpm -qa | fgrep kernel | fgrep debuginfo
kernel-debuginfo-common-x86_64-5.9.8-200.fc33.x86_64
kernel-debuginfo-5.9.8-200.fc33.x86_64
kernel-tools-debuginfo-5.9.7-200.fc33.x86_64
[root@f33 ~]#
~                          

Thanks a lot
-- 
Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzender des Aufsichtsrats: Gregor Pillen
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294

Re: Fedora 33 and perf probe failures

[Masami Hiramatsu]

Hi Thomas,

On Wed, 18 Nov 2020 17:37:21 +0100
Thomas Richter <tmricht@linux.ibm.com> wrote:

> I debugged the failure of some perf test cases on Fedora 33. The following
> test cases fail on s390 and x86_64 using

Thanks for the report!
Let me setup Fedora33.

> 
> [root@f33 yum.repos.d]# uname -a
> Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020
>                                 x86_64 x86_64 x86_64 GNU/Linux
> [root@f33 yum.repos.d]#
> 
> [root@f33 yum.repos.d]# perf test -F 74 77 78
> 74: Use vfs_getname probe to get syscall args filenames
>                 :Failed to write event: Invalid argument
> Error: Failed to add events.
> FAILED!
> 77: Check open filename arg using perf trace + vfs_getname
>                 :Failed to write event: Invalid argument
> Error: Failed to add events.
> FAILED!
> 78: Add vfs_getname probe to get syscall args filenames
>                 :Failed to write event: Invalid argument
> Error: Failed to add events.
> FAILED!
> [root@f33 yum.repos.d]#

BTW, do we have vfs_getname in the kernel?

> 
> The root cause is the output of perf probe -L which returns:
> [root@f33 yum.repos.d]# perf probe -L getname_flags
> Specified source line is not found.
> Error: Failed to show lines.

Hmm, could you run it with -vvv option?

> [root@f33 yum.repos.d]#
> 
> whereas on my Fedora 32 installation this command shows
> [root@t35lp46 perf]# cat /etc/redhat-release
> Fedora release 32 (Thirty Two)
> [root@t35lp46 perf]#
> 
> [root@t35lp46 perf]# ./perf probe -L getname_flags | tail -10
>      68                         return ERR_PTR(-ENOENT);
>                         }
>                 }
> 
>      72         result->uptr = filename;
>      73         result->aname = NULL;
>      74         audit_getname(result);
>                 return result;
> }
> 
> [root@t35lp46 perf]#
> 
> Any ideas how to fix this? Is this failure related to a missing debuginfod
> setup, even when I have installed the debuginfo packages for the kernel:

If you can find the vmlinux in debuginfo package, could you try
eu-addr2line to find getname_flags?
 
eu-addr2line -e /somewhere/to/vmlinux getname_flags+0

Thank you,

> 
> [root@f33 ~]# perf probe -L getname_flags
> Specified source line is not found.
>   Error: Failed to show lines.
> [root@f33 ~]# uname -a
> Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
> [root@f33 ~]# rpm -qa | fgrep kernel | fgrep debuginfo
> kernel-debuginfo-common-x86_64-5.9.8-200.fc33.x86_64
> kernel-debuginfo-5.9.8-200.fc33.x86_64
> kernel-tools-debuginfo-5.9.7-200.fc33.x86_64
> [root@f33 ~]#
> ~                          
> 
> Thanks a lot
> -- 
> Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
> --
> Vorsitzender des Aufsichtsrats: Gregor Pillen
> Geschäftsführung: Dirk Wittkopp
> Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: Fedora 33 and perf probe failures

[Thomas Richter]

On 11/19/20 2:07 AM, Masami Hiramatsu wrote:
> Hi Thomas,
> 
> On Wed, 18 Nov 2020 17:37:21 +0100
> Thomas Richter <tmricht@linux.ibm.com> wrote:
> 
>> I debugged the failure of some perf test cases on Fedora 33. The following
>> test cases fail on s390 and x86_64 using
> 
> Thanks for the report!
> Let me setup Fedora33.
> 
>>
>> [root@f33 yum.repos.d]# uname -a
>> Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020
>>                                 x86_64 x86_64 x86_64 GNU/Linux
>> [root@f33 yum.repos.d]#
>>
>> [root@f33 yum.repos.d]# perf test -F 74 77 78
>> 74: Use vfs_getname probe to get syscall args filenames
>>                 :Failed to write event: Invalid argument
>> Error: Failed to add events.
>> FAILED!
>> 77: Check open filename arg using perf trace + vfs_getname
>>                 :Failed to write event: Invalid argument
>> Error: Failed to add events.
>> FAILED!
>> 78: Add vfs_getname probe to get syscall args filenames
>>                 :Failed to write event: Invalid argument
>> Error: Failed to add events.
>> FAILED!
>> [root@f33 yum.repos.d]#
> 
> BTW, do we have vfs_getname in the kernel?
> 

No, that is the name of the probe when calling perf probe command,
as in .../perf/tests/shell/lib/probe_vfs_getname.sh:

perf probe -q "vfs_getname=getname_flags:...."
The probe is set on kernel function getname_flags()
in fs/namei.c source file and named vfs_getname inside
perf/tracing subsystem.

>>
>> The root cause is the output of perf probe -L which returns:
>> [root@f33 yum.repos.d]# perf probe -L getname_flags
>> Specified source line is not found.
>> Error: Failed to show lines.
> 
> Hmm, could you run it with -vvv option?

[root@f33 ~]# uname -a
Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
[root@f33 ~]# cat /etc/fedora-release 
Fedora release 33 (Thirty Three)
[root@f33 ~]# perf kallsyms getname_flags
getname_flags: [kernel] [kernel.kallsyms] 0xffffffffa8325000-0xffffffffa8325060 (0xffffffffa8325000-0xffffffffa8325060)
[root@f33 ~]# find / -name vmlinux
/home/richter/linux/arch/x86/boot/compressed/vmlinux
/home/richter/linux/vmlinux
/usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux
/sys/kernel/btf/vmlinux
[root@f33 ~]# nm -g /usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux| fgrep getname_flags
ffffffff81325000 T getname_flags
[root@f33 ~]# 

[root@f33 ~]# perf probe -vvv -L getname_flags
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
fname: ./include/linux/fs.h, lineno:2527
New line range: 2527 to 2147483647
path: (null)
Specified source line is not found.
  Error: Failed to show lines. Reason: No such file or directory (Code: -2)
[root@f33 ~]# 

> 
>> [root@f33 yum.repos.d]#
>>
>> whereas on my Fedora 32 installation this command shows
>> [root@t35lp46 perf]# cat /etc/redhat-release
>> Fedora release 32 (Thirty Two)
>> [root@t35lp46 perf]#
>>
>> [root@t35lp46 perf]# ./perf probe -L getname_flags | tail -10
>>      68                         return ERR_PTR(-ENOENT);
>>                         }
>>                 }
>>
>>      72         result->uptr = filename;
>>      73         result->aname = NULL;
>>      74         audit_getname(result);
>>                 return result;
>> }
>>
>> [root@t35lp46 perf]#
>>
>> Any ideas how to fix this? Is this failure related to a missing debuginfod
>> setup, even when I have installed the debuginfo packages for the kernel:
> 
> If you can find the vmlinux in debuginfo package, could you try
> eu-addr2line to find getname_flags?
>  
> eu-addr2line -e /somewhere/to/vmlinux getname_flags+0

[root@f33 ~]# eu-addr2line -e /usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux  getname_flags+0
fs/namei.c:129:1
[root@f33 ~]# 

> 
> Thank you,
> 

You are welcome, thanks for looking into this.

I have added my Fedora32 output for completeness:

[root@t35lp46 perf]# ./perf probe -vvv -L getname_flags
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/5.10.0-rc4d-perf+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/5.10.0-rc4d-perf+/build/vmlinux
fname: fs/namei.c, lineno:128
New line range: 128 to 2147483647
Get 20989 lines from this CU
path: fs/namei.c
Search fs/namei.c from debuginfod -> -38
Failed to find fs/namei.c in debuginfod (8a690c7c154db1283cebb8953128584dd4f94b3d)
<getname_flags@/root/linux/fs/namei.c:0>
      0  getname_flags(const char __user *filename, int flags, int *empty)
         {
      2         struct filename *result;
                char *kname;
                int len;
......

root@t35lp46 perf]# eu-addr2line -e ~/linux/vmlinux  getname_flags+0
fs/namei.c:129:1
[root@t35lp46 perf]# 


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

Re: Fedora 33 and perf probe failures

[Masami Hiramatsu]

Hi,

On Thu, 19 Nov 2020 09:16:57 +0100
Thomas Richter <tmricht@linux.ibm.com> wrote:

> On 11/19/20 2:07 AM, Masami Hiramatsu wrote:
> > Hi Thomas,
> > 
> > On Wed, 18 Nov 2020 17:37:21 +0100
> > Thomas Richter <tmricht@linux.ibm.com> wrote:
> > 
> >> I debugged the failure of some perf test cases on Fedora 33. The following
> >> test cases fail on s390 and x86_64 using
> > 
> > Thanks for the report!
> > Let me setup Fedora33.
> > 
> >>
> >> [root@f33 yum.repos.d]# uname -a
> >> Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020
> >>                                 x86_64 x86_64 x86_64 GNU/Linux
> >> [root@f33 yum.repos.d]#
> >>
> >> [root@f33 yum.repos.d]# perf test -F 74 77 78
> >> 74: Use vfs_getname probe to get syscall args filenames
> >>                 :Failed to write event: Invalid argument
> >> Error: Failed to add events.
> >> FAILED!
> >> 77: Check open filename arg using perf trace + vfs_getname
> >>                 :Failed to write event: Invalid argument
> >> Error: Failed to add events.
> >> FAILED!
> >> 78: Add vfs_getname probe to get syscall args filenames
> >>                 :Failed to write event: Invalid argument
> >> Error: Failed to add events.
> >> FAILED!
> >> [root@f33 yum.repos.d]#
> > 
> > BTW, do we have vfs_getname in the kernel?
> > 
> 
> No, that is the name of the probe when calling perf probe command,
> as in .../perf/tests/shell/lib/probe_vfs_getname.sh:
> 
> perf probe -q "vfs_getname=getname_flags:...."

Ah, OK.

> The probe is set on kernel function getname_flags()
> in fs/namei.c source file and named vfs_getname inside
> perf/tracing subsystem.

Hmm, this seems debuginfo is not correctly handled.


> >> The root cause is the output of perf probe -L which returns:
> >> [root@f33 yum.repos.d]# perf probe -L getname_flags
> >> Specified source line is not found.
> >> Error: Failed to show lines.
> > 
> > Hmm, could you run it with -vvv option?
> 
> [root@f33 ~]# uname -a
> Linux f33 5.9.8-200.fc33.x86_64 #1 SMP Tue Nov 10 21:58:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
> [root@f33 ~]# cat /etc/fedora-release 
> Fedora release 33 (Thirty Three)
> [root@f33 ~]# perf kallsyms getname_flags
> getname_flags: [kernel] [kernel.kallsyms] 0xffffffffa8325000-0xffffffffa8325060 (0xffffffffa8325000-0xffffffffa8325060)
> [root@f33 ~]# find / -name vmlinux
> /home/richter/linux/arch/x86/boot/compressed/vmlinux
> /home/richter/linux/vmlinux
> /usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux
> /sys/kernel/btf/vmlinux
> [root@f33 ~]# nm -g /usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux| fgrep getname_flags
> ffffffff81325000 T getname_flags
> [root@f33 ~]# 
> 
> [root@f33 ~]# perf probe -vvv -L getname_flags
> Looking at the vmlinux_path (8 entries long)
> Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
> Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
> fname: ./include/linux/fs.h, lineno:2527
> New line range: 2527 to 2147483647
> path: (null)
> Specified source line is not found.

The fname seems wrong, there is a declaration of getname_flags, but not
the definition. Hmm, maybe the dwarf format is different?

>   Error: Failed to show lines. Reason: No such file or directory (Code: -2)
> [root@f33 ~]# 
> 
> > 
> >> [root@f33 yum.repos.d]#
> >>
> >> whereas on my Fedora 32 installation this command shows
> >> [root@t35lp46 perf]# cat /etc/redhat-release
> >> Fedora release 32 (Thirty Two)
> >> [root@t35lp46 perf]#
> >>
> >> [root@t35lp46 perf]# ./perf probe -L getname_flags | tail -10
> >>      68                         return ERR_PTR(-ENOENT);
> >>                         }
> >>                 }
> >>
> >>      72         result->uptr = filename;
> >>      73         result->aname = NULL;
> >>      74         audit_getname(result);
> >>                 return result;
> >> }
> >>
> >> [root@t35lp46 perf]#
> >>
> >> Any ideas how to fix this? Is this failure related to a missing debuginfod
> >> setup, even when I have installed the debuginfo packages for the kernel:
> > 
> > If you can find the vmlinux in debuginfo package, could you try
> > eu-addr2line to find getname_flags?
> >  
> > eu-addr2line -e /somewhere/to/vmlinux getname_flags+0
> 
> [root@f33 ~]# eu-addr2line -e /usr/lib/debug/usr/lib/modules/5.9.8-200.fc33.x86_64/vmlinux  getname_flags+0
> fs/namei.c:129:1
> [root@f33 ~]# 

OK, so elfutils can decode it.
I'll try to decode dwarf, trace elfutils and find what happens.

Thank you,

> 
> > 
> > Thank you,
> > 
> 
> You are welcome, thanks for looking into this.
> 
> I have added my Fedora32 output for completeness:
> 
> [root@t35lp46 perf]# ./perf probe -vvv -L getname_flags
> Looking at the vmlinux_path (8 entries long)
> Using /lib/modules/5.10.0-rc4d-perf+/build/vmlinux for symbols
> Open Debuginfo file: /lib/modules/5.10.0-rc4d-perf+/build/vmlinux
> fname: fs/namei.c, lineno:128
> New line range: 128 to 2147483647
> Get 20989 lines from this CU
> path: fs/namei.c
> Search fs/namei.c from debuginfod -> -38
> Failed to find fs/namei.c in debuginfod (8a690c7c154db1283cebb8953128584dd4f94b3d)
> <getname_flags@/root/linux/fs/namei.c:0>
>       0  getname_flags(const char __user *filename, int flags, int *empty)
>          {
>       2         struct filename *result;
>                 char *kname;
>                 int len;
> ......
> 
> root@t35lp46 perf]# eu-addr2line -e ~/linux/vmlinux  getname_flags+0
> fs/namei.c:129:1
> [root@t35lp46 perf]# 
> 
> 
> -- 
> Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
> --
> Vorsitzender des Aufsichtsrats: Gregor Pillen
> Geschäftsführung: Dirk Wittkopp
> Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: Fedora 33 and perf probe failures

[Masami Hiramatsu]

Hi Thomas,

I've setup fedora33 and found strange debuginfo.

On Thu, 19 Nov 2020 09:16:57 +0100
Thomas Richter <tmricht@linux.ibm.com> wrote:

> [root@f33 ~]# perf probe -vvv -L getname_flags
> Looking at the vmlinux_path (8 entries long)
> Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
> Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
> fname: ./include/linux/fs.h, lineno:2527
> New line range: 2527 to 2147483647
> path: (null)
> Specified source line is not found.
>   Error: Failed to show lines. Reason: No such file or directory (Code: -2)

Above error was reproduced, and I found that the perf-probe's routine
failed to find the real function definition.

I decoded the vmlinux with eu-readelf -w, and I found there were 2
entries (DIEs) for the getname_flags.

(1)
 [2dbe7c6]    subprogram           abbrev: 54
             external             (flag_present) yes
             name                 (strp) "getname_flags"
             decl_file            (data1) fs.h (8)
             decl_line            (data2) 2527
             decl_column          (data1) 25
             prototyped           (flag_present) yes
             type                 (ref4) [2dbe7e7]
             sibling              (ref4) [2dbe7e7]
 [2dbe7d7]      formal_parameter     abbrev: 4
               type                 (ref4) [2da9721]
 [2dbe7dc]      formal_parameter     abbrev: 4
               type                 (ref4) [2da97a1]
 [2dbe7e1]      formal_parameter     abbrev: 4
               type                 (ref4) [2dabbdd]

(2)
 [2e0fde0]    subprogram           abbrev: 162
             external             (flag_present) yes
             name                 (strp) "getname_flags"
             decl_file            (data1) namei.c (1)
             decl_line            (data1) 128
             decl_column          (data1) 1
             prototyped           (flag_present) yes
             type                 (ref4) [2dfced6]
             inline               (data1) inlined (1)
             sibling              (ref4) [2e0fe49]
 [2e0fdf2]      formal_parameter     abbrev: 31
               name                 (strp) "filename"
               decl_file            (data1) namei.c (1)
               decl_line            (data1) 128
               decl_column          (data1) 34
               type                 (ref4) [2de77f3]
 [2e0fdfe]      formal_parameter     abbrev: 31
               name                 (strp) "flags"
               decl_file            (data1) namei.c (1)
               decl_line            (data1) 128
               decl_column          (data1) 48
               type                 (ref4) [2de7873]
 [2e0fe0a]      formal_parameter     abbrev: 31
               name                 (strp) "empty"
               decl_file            (data1) namei.c (1)
               decl_line            (data1) 128
               decl_column          (data1) 60
               type                 (ref4) [2de9ce4]

The first one is not the actual function, but that is a DIE
for the declaration. However, this DIE doesn't have DW_AT_declaration
attribute, it should be there if the DIE represents the declaration.

In perf, die_is_func_def() checks that attribute, and if the DIE doen't
have DW_AT_declaration, line_range_search_cb() think the DIE represents
the function definition (function prototype). And search the instance
to find the line range.

However, since the (1) has no DW_AT_declaration, perf probe was mislead
that the DIE is the function definition, and search the function instance
which links to the DIE. And it failed to find any instances because
the DIE it found was just a prototype in the header file. (But it seems
some call-site DIE refers the declaration DIE.)

Let me try to fix if we skip the first DIE.

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: Fedora 33 and perf probe failures

[Arnaldo Carvalho de Melo]

Em Thu, Nov 26, 2020 at 10:08:48PM +0900, Masami Hiramatsu escreveu:
> Hi Thomas,
> 
> I've setup fedora33 and found strange debuginfo.
> 
> On Thu, 19 Nov 2020 09:16:57 +0100
> Thomas Richter <tmricht@linux.ibm.com> wrote:
> 
> > [root@f33 ~]# perf probe -vvv -L getname_flags
> > Looking at the vmlinux_path (8 entries long)
> > Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
> > Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
> > fname: ./include/linux/fs.h, lineno:2527
> > New line range: 2527 to 2147483647
> > path: (null)
> > Specified source line is not found.
> >   Error: Failed to show lines. Reason: No such file or directory (Code: -2)
> 
> Above error was reproduced, and I found that the perf-probe's routine
> failed to find the real function definition.
> 
> I decoded the vmlinux with eu-readelf -w, and I found there were 2
> entries (DIEs) for the getname_flags.
> 
> (1)
>  [2dbe7c6]    subprogram           abbrev: 54
>              external             (flag_present) yes
>              name                 (strp) "getname_flags"
>              decl_file            (data1) fs.h (8)
>              decl_line            (data2) 2527
>              decl_column          (data1) 25
>              prototyped           (flag_present) yes
>              type                 (ref4) [2dbe7e7]
>              sibling              (ref4) [2dbe7e7]
>  [2dbe7d7]      formal_parameter     abbrev: 4
>                type                 (ref4) [2da9721]
>  [2dbe7dc]      formal_parameter     abbrev: 4
>                type                 (ref4) [2da97a1]
>  [2dbe7e1]      formal_parameter     abbrev: 4
>                type                 (ref4) [2dabbdd]
> 
> (2)
>  [2e0fde0]    subprogram           abbrev: 162
>              external             (flag_present) yes
>              name                 (strp) "getname_flags"
>              decl_file            (data1) namei.c (1)
>              decl_line            (data1) 128
>              decl_column          (data1) 1
>              prototyped           (flag_present) yes
>              type                 (ref4) [2dfced6]
>              inline               (data1) inlined (1)
>              sibling              (ref4) [2e0fe49]
>  [2e0fdf2]      formal_parameter     abbrev: 31
>                name                 (strp) "filename"
>                decl_file            (data1) namei.c (1)
>                decl_line            (data1) 128
>                decl_column          (data1) 34
>                type                 (ref4) [2de77f3]
>  [2e0fdfe]      formal_parameter     abbrev: 31
>                name                 (strp) "flags"
>                decl_file            (data1) namei.c (1)
>                decl_line            (data1) 128
>                decl_column          (data1) 48
>                type                 (ref4) [2de7873]
>  [2e0fe0a]      formal_parameter     abbrev: 31
>                name                 (strp) "empty"
>                decl_file            (data1) namei.c (1)
>                decl_line            (data1) 128
>                decl_column          (data1) 60
>                type                 (ref4) [2de9ce4]
> 
> The first one is not the actual function, but that is a DIE
> for the declaration. However, this DIE doesn't have DW_AT_declaration
> attribute, it should be there if the DIE represents the declaration.

Its a bug in some gdb versions, see:

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=97060

And here is the pahole cset dealing with that:

https://git.kernel.org/pub/scm/devel/pahole/pahole.git/commit/?h=5a22c2de79fb9edf2d36ff4e8d440a862fc99c2a
 
> In perf, die_is_func_def() checks that attribute, and if the DIE doen't
> have DW_AT_declaration, line_range_search_cb() think the DIE represents
> the function definition (function prototype). And search the instance
> to find the line range.
> 
> However, since the (1) has no DW_AT_declaration, perf probe was mislead
> that the DIE is the function definition, and search the function instance
> which links to the DIE. And it failed to find any instances because
> the DIE it found was just a prototype in the header file. (But it seems
> some call-site DIE refers the declaration DIE.)
> 
> Let me try to fix if we skip the first DIE.
> 
> Thank you,
> 
> -- 
> Masami Hiramatsu <mhiramat@kernel.org>

-- 

- Arnaldo

Re: Fedora 33 and perf probe failures

[Masami Hiramatsu]

On Thu, 26 Nov 2020 14:28:49 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Thu, Nov 26, 2020 at 10:08:48PM +0900, Masami Hiramatsu escreveu:
> > Hi Thomas,
> > 
> > I've setup fedora33 and found strange debuginfo.
> > 
> > On Thu, 19 Nov 2020 09:16:57 +0100
> > Thomas Richter <tmricht@linux.ibm.com> wrote:
> > 
> > > [root@f33 ~]# perf probe -vvv -L getname_flags
> > > Looking at the vmlinux_path (8 entries long)
> > > Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
> > > Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
> > > fname: ./include/linux/fs.h, lineno:2527
> > > New line range: 2527 to 2147483647
> > > path: (null)
> > > Specified source line is not found.
> > >   Error: Failed to show lines. Reason: No such file or directory (Code: -2)
> > 
> > Above error was reproduced, and I found that the perf-probe's routine
> > failed to find the real function definition.
> > 
> > I decoded the vmlinux with eu-readelf -w, and I found there were 2
> > entries (DIEs) for the getname_flags.
> > 
> > (1)
> >  [2dbe7c6]    subprogram           abbrev: 54
> >              external             (flag_present) yes
> >              name                 (strp) "getname_flags"
> >              decl_file            (data1) fs.h (8)
> >              decl_line            (data2) 2527
> >              decl_column          (data1) 25
> >              prototyped           (flag_present) yes
> >              type                 (ref4) [2dbe7e7]
> >              sibling              (ref4) [2dbe7e7]
> >  [2dbe7d7]      formal_parameter     abbrev: 4
> >                type                 (ref4) [2da9721]
> >  [2dbe7dc]      formal_parameter     abbrev: 4
> >                type                 (ref4) [2da97a1]
> >  [2dbe7e1]      formal_parameter     abbrev: 4
> >                type                 (ref4) [2dabbdd]
> > 
> > (2)
> >  [2e0fde0]    subprogram           abbrev: 162
> >              external             (flag_present) yes
> >              name                 (strp) "getname_flags"
> >              decl_file            (data1) namei.c (1)
> >              decl_line            (data1) 128
> >              decl_column          (data1) 1
> >              prototyped           (flag_present) yes
> >              type                 (ref4) [2dfced6]
> >              inline               (data1) inlined (1)
> >              sibling              (ref4) [2e0fe49]
> >  [2e0fdf2]      formal_parameter     abbrev: 31
> >                name                 (strp) "filename"
> >                decl_file            (data1) namei.c (1)
> >                decl_line            (data1) 128
> >                decl_column          (data1) 34
> >                type                 (ref4) [2de77f3]
> >  [2e0fdfe]      formal_parameter     abbrev: 31
> >                name                 (strp) "flags"
> >                decl_file            (data1) namei.c (1)
> >                decl_line            (data1) 128
> >                decl_column          (data1) 48
> >                type                 (ref4) [2de7873]
> >  [2e0fe0a]      formal_parameter     abbrev: 31
> >                name                 (strp) "empty"
> >                decl_file            (data1) namei.c (1)
> >                decl_line            (data1) 128
> >                decl_column          (data1) 60
> >                type                 (ref4) [2de9ce4]
> > 
> > The first one is not the actual function, but that is a DIE
> > for the declaration. However, this DIE doesn't have DW_AT_declaration
> > attribute, it should be there if the DIE represents the declaration.
> 
> Its a bug in some gdb versions, see:
> 
> https://gcc.gnu.org/bugzilla/show_bug.cgi?id=97060

Thanks, so there is a compiler bug.

> 
> And here is the pahole cset dealing with that:
> 
> https://git.kernel.org/pub/scm/devel/pahole/pahole.git/commit/?h=5a22c2de79fb9edf2d36ff4e8d440a862fc99c2a

Oh, that's nice!

Anyway, I found how I can handle it for --lines option.
Let me fix it first.

Thank you,


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: Fedora 33 and perf probe failures

[Arnaldo Carvalho de Melo]

Em Fri, Nov 27, 2020 at 09:10:04AM +0900, Masami Hiramatsu escreveu:
> On Thu, 26 Nov 2020 14:28:49 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
> > Em Thu, Nov 26, 2020 at 10:08:48PM +0900, Masami Hiramatsu escreveu:
> > > Hi Thomas,
> > > 
> > > I've setup fedora33 and found strange debuginfo.
> > > 
> > > On Thu, 19 Nov 2020 09:16:57 +0100
> > > Thomas Richter <tmricht@linux.ibm.com> wrote:
> > > 
> > > > [root@f33 ~]# perf probe -vvv -L getname_flags
> > > > Looking at the vmlinux_path (8 entries long)
> > > > Using /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux for symbols
> > > > Open Debuginfo file: /lib/modules/5.9.8-200.fc33.x86_64/build/vmlinux
> > > > fname: ./include/linux/fs.h, lineno:2527
> > > > New line range: 2527 to 2147483647
> > > > path: (null)
> > > > Specified source line is not found.
> > > >   Error: Failed to show lines. Reason: No such file or directory (Code: -2)
> > > 
> > > Above error was reproduced, and I found that the perf-probe's routine
> > > failed to find the real function definition.
> > > 
> > > I decoded the vmlinux with eu-readelf -w, and I found there were 2
> > > entries (DIEs) for the getname_flags.
> > > 
> > > (1)
> > >  [2dbe7c6]    subprogram           abbrev: 54
> > >              external             (flag_present) yes
> > >              name                 (strp) "getname_flags"
> > >              decl_file            (data1) fs.h (8)
> > >              decl_line            (data2) 2527
> > >              decl_column          (data1) 25
> > >              prototyped           (flag_present) yes
> > >              type                 (ref4) [2dbe7e7]
> > >              sibling              (ref4) [2dbe7e7]
> > >  [2dbe7d7]      formal_parameter     abbrev: 4
> > >                type                 (ref4) [2da9721]
> > >  [2dbe7dc]      formal_parameter     abbrev: 4
> > >                type                 (ref4) [2da97a1]
> > >  [2dbe7e1]      formal_parameter     abbrev: 4
> > >                type                 (ref4) [2dabbdd]
> > > 
> > > (2)
> > >  [2e0fde0]    subprogram           abbrev: 162
> > >              external             (flag_present) yes
> > >              name                 (strp) "getname_flags"
> > >              decl_file            (data1) namei.c (1)
> > >              decl_line            (data1) 128
> > >              decl_column          (data1) 1
> > >              prototyped           (flag_present) yes
> > >              type                 (ref4) [2dfced6]
> > >              inline               (data1) inlined (1)
> > >              sibling              (ref4) [2e0fe49]
> > >  [2e0fdf2]      formal_parameter     abbrev: 31
> > >                name                 (strp) "filename"
> > >                decl_file            (data1) namei.c (1)
> > >                decl_line            (data1) 128
> > >                decl_column          (data1) 34
> > >                type                 (ref4) [2de77f3]
> > >  [2e0fdfe]      formal_parameter     abbrev: 31
> > >                name                 (strp) "flags"
> > >                decl_file            (data1) namei.c (1)
> > >                decl_line            (data1) 128
> > >                decl_column          (data1) 48
> > >                type                 (ref4) [2de7873]
> > >  [2e0fe0a]      formal_parameter     abbrev: 31
> > >                name                 (strp) "empty"
> > >                decl_file            (data1) namei.c (1)
> > >                decl_line            (data1) 128
> > >                decl_column          (data1) 60
> > >                type                 (ref4) [2de9ce4]
> > > 
> > > The first one is not the actual function, but that is a DIE
> > > for the declaration. However, this DIE doesn't have DW_AT_declaration
> > > attribute, it should be there if the DIE represents the declaration.
> > 
> > Its a bug in some gdb versions, see:

ARgh, s/gdb/gcc/ :-)

> > https://gcc.gnu.org/bugzilla/show_bug.cgi?id=97060
> 
> Thanks, so there is a compiler bug.
> 
> > 
> > And here is the pahole cset dealing with that:
> > 
> > https://git.kernel.org/pub/scm/devel/pahole/pahole.git/commit/?h=5a22c2de79fb9edf2d36ff4e8d440a862fc99c2a
> 
> Oh, that's nice!
> 
> Anyway, I found how I can handle it for --lines option.
> Let me fix it first.
> 
> Thank you,
> 
> 
> -- 
> Masami Hiramatsu <mhiramat@kernel.org>

-- 

- Arnaldo

[PATCH 1/2] perf-probe: Fix to die_entrypc() returns error correctly

[Masami Hiramatsu]

Fix die_entrypc() to return error correctly if the DIE has no
DW_AT_ranges attribute. Since dwarf_ranges() will treat the case
as an empty ranges and return 0, we have to check it by ourselves.

Fixes: 91e2f539eeda ("perf probe: Fix to show function entry line as probe-able")
Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/perf/util/dwarf-aux.c |    8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/tools/perf/util/dwarf-aux.c b/tools/perf/util/dwarf-aux.c
index aa898014ad12..03c1a39c312a 100644
--- a/tools/perf/util/dwarf-aux.c
+++ b/tools/perf/util/dwarf-aux.c
@@ -373,6 +373,7 @@ bool die_is_func_def(Dwarf_Die *dw_die)
 int die_entrypc(Dwarf_Die *dw_die, Dwarf_Addr *addr)
 {
 	Dwarf_Addr base, end;
+	Dwarf_Attribute attr;
 
 	if (!addr)
 		return -EINVAL;
@@ -380,6 +381,13 @@ int die_entrypc(Dwarf_Die *dw_die, Dwarf_Addr *addr)
 	if (dwarf_entrypc(dw_die, addr) == 0)
 		return 0;
 
+	/*
+	 *  Since the dwarf_ranges() will return 0 if there is no
+	 * DW_AT_ranges attribute, we should check it first.
+	 */
+	if (!dwarf_attr(dw_die, DW_AT_ranges, &attr))
+		return -ENOENT;
+
 	return dwarf_ranges(dw_die, 0, &base, addr, &end) < 0 ? -ENOENT : 0;
 }
 

[PATCH 2/2] perf-probe: Change function definition check due to broken dwarf

[Masami Hiramatsu]

Since some gcc generates a broken DWARF which lacks DW_AT_declaration
attribute from the subprogram DIE of function prototype.
(https://gcc.gnu.org/bugzilla/show_bug.cgi?id=97060)

So, in addition to the DW_AT_declaration check, we also check the
subprogram DIE has DW_AT_inline or actual entry pc.

Reported-by: Thomas Richter <tmricht@linux.ibm.com>
Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/perf/util/dwarf-aux.c    |   20 ++++++++++++++++++--
 tools/perf/util/probe-finder.c |    3 +--
 2 files changed, 19 insertions(+), 4 deletions(-)

diff --git a/tools/perf/util/dwarf-aux.c b/tools/perf/util/dwarf-aux.c
index 03c1a39c312a..7b2d471a6419 100644
--- a/tools/perf/util/dwarf-aux.c
+++ b/tools/perf/util/dwarf-aux.c
@@ -356,9 +356,25 @@ bool die_is_signed_type(Dwarf_Die *tp_die)
 bool die_is_func_def(Dwarf_Die *dw_die)
 {
 	Dwarf_Attribute attr;
+	Dwarf_Addr addr = 0;
+
+	if (dwarf_tag(dw_die) != DW_TAG_subprogram)
+		return false;
+
+	if (dwarf_attr(dw_die, DW_AT_declaration, &attr))
+		return false;
 
-	return (dwarf_tag(dw_die) == DW_TAG_subprogram &&
-		dwarf_attr(dw_die, DW_AT_declaration, &attr) == NULL);
+	/*
+	 * DW_AT_declaration can be lost from function declaration
+	 * by gcc's bug #97060.
+	 * So we need to check this subprogram DIE has DW_AT_inline
+	 * or an entry address.
+	 */
+	if (!dwarf_attr(dw_die, DW_AT_inline, &attr) &&
+	    die_entrypc(dw_die, &addr) < 0)
+		return false;
+
+	return true;
 }
 
 /**
diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index 2c4061035f77..76dd349aa48d 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -1885,8 +1885,7 @@ static int line_range_search_cb(Dwarf_Die *sp_die, void *data)
 	if (lr->file && strtailcmp(lr->file, dwarf_decl_file(sp_die)))
 		return DWARF_CB_OK;
 
-	if (die_is_func_def(sp_die) &&
-	    die_match_name(sp_die, lr->function)) {
+	if (die_match_name(sp_die, lr->function) && die_is_func_def(sp_die)) {
 		lf->fname = dwarf_decl_file(sp_die);
 		dwarf_decl_line(sp_die, &lr->offset);
 		pr_debug("fname: %s, lineno:%d\n", lf->fname, lr->offset);

Re: [PATCH 2/2] perf-probe: Change function definition check due to broken dwarf

[Arnaldo Carvalho de Melo]

Em Fri, Nov 27, 2020 at 02:48:55PM +0900, Masami Hiramatsu escreveu:
> Since some gcc generates a broken DWARF which lacks DW_AT_declaration
> attribute from the subprogram DIE of function prototype.
> (https://gcc.gnu.org/bugzilla/show_bug.cgi?id=97060)
> 
> So, in addition to the DW_AT_declaration check, we also check the
> subprogram DIE has DW_AT_inline or actual entry pc.

Thanks, applied and tested both patches on a fedora 33 system where
previously those tests were failing:

    Committer testing:

      # cat /etc/fedora-release
      Fedora release 33 (Thirty Three)
      #

    Before:

      # perf test vfs_getname
      78: Use vfs_getname probe to get syscall args filenames             : FAILED!
      79: Check open filename arg using perf trace + vfs_getname          : FAILED!
      81: Add vfs_getname probe to get syscall args filenames             : FAILED!
      #

    After:

      # perf test vfs_getname
      78: Use vfs_getname probe to get syscall args filenames             : Ok
      79: Check open filename arg using perf trace + vfs_getname          : Ok
      81: Add vfs_getname probe to get syscall args filenames             : Ok
      #


- Arnaldo
 
> Reported-by: Thomas Richter <tmricht@linux.ibm.com>
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> ---
>  tools/perf/util/dwarf-aux.c    |   20 ++++++++++++++++++--
>  tools/perf/util/probe-finder.c |    3 +--
>  2 files changed, 19 insertions(+), 4 deletions(-)
> 
> diff --git a/tools/perf/util/dwarf-aux.c b/tools/perf/util/dwarf-aux.c
> index 03c1a39c312a..7b2d471a6419 100644
> --- a/tools/perf/util/dwarf-aux.c
> +++ b/tools/perf/util/dwarf-aux.c
> @@ -356,9 +356,25 @@ bool die_is_signed_type(Dwarf_Die *tp_die)
>  bool die_is_func_def(Dwarf_Die *dw_die)
>  {
>  	Dwarf_Attribute attr;
> +	Dwarf_Addr addr = 0;
> +
> +	if (dwarf_tag(dw_die) != DW_TAG_subprogram)
> +		return false;
> +
> +	if (dwarf_attr(dw_die, DW_AT_declaration, &attr))
> +		return false;
>  
> -	return (dwarf_tag(dw_die) == DW_TAG_subprogram &&
> -		dwarf_attr(dw_die, DW_AT_declaration, &attr) == NULL);
> +	/*
> +	 * DW_AT_declaration can be lost from function declaration
> +	 * by gcc's bug #97060.
> +	 * So we need to check this subprogram DIE has DW_AT_inline
> +	 * or an entry address.
> +	 */
> +	if (!dwarf_attr(dw_die, DW_AT_inline, &attr) &&
> +	    die_entrypc(dw_die, &addr) < 0)
> +		return false;
> +
> +	return true;
>  }
>  
>  /**
> diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
> index 2c4061035f77..76dd349aa48d 100644
> --- a/tools/perf/util/probe-finder.c
> +++ b/tools/perf/util/probe-finder.c
> @@ -1885,8 +1885,7 @@ static int line_range_search_cb(Dwarf_Die *sp_die, void *data)
>  	if (lr->file && strtailcmp(lr->file, dwarf_decl_file(sp_die)))
>  		return DWARF_CB_OK;
>  
> -	if (die_is_func_def(sp_die) &&
> -	    die_match_name(sp_die, lr->function)) {
> +	if (die_match_name(sp_die, lr->function) && die_is_func_def(sp_die)) {
>  		lf->fname = dwarf_decl_file(sp_die);
>  		dwarf_decl_line(sp_die, &lr->offset);
>  		pr_debug("fname: %s, lineno:%d\n", lf->fname, lr->offset);
> 

-- 

- Arnaldo