[BUG?] semantic error: failed to retrieve location attribute for local

[BUG?] semantic error: failed to retrieve location attribute for local

[Jan Blunck]

I have the following simple probe:

probe kernel.inline("real_lookup")
{
        printf("%s - %s(%s): %s\n", thread_indent(0), probefunc(),
                   kernel_string($parent->d_name->name),
                   kernel_string($name->name))
}

The full error message is as follows:

jblunck:~/systemtap$ stap -vvvv -p2 real_lookup.stp
Created temporary directory "/tmp/stapABdKKf"
Searched '/usr/share/systemtap/tapset/2.6.18.2-34-default/i686/*.stp', match
count 0
Searched '/usr/share/systemtap/tapset/2.6.18.2-34-default/*.stp', match count
0
Searched '/usr/share/systemtap/tapset/2.6.18.2/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/2.6.18.2/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/2.6.18/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/2.6.18/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/2.6/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/2.6/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/i686/*.stp', match count 1
Searched '/usr/share/systemtap/tapset/*.stp', match count 33
Searched '/usr/share/systemtap/tapset/LKET/2.6.18.2-34-default/i686/*.stp',
match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6.18.2-34-default/*.stp', match
count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6.18.2/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6.18.2/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6.18/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6.18/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/2.6/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/i686/*.stp', match count 0
Searched '/usr/share/systemtap/tapset/LKET/*.stp', match count 19
Pass 1: parsed user script and 53 library script(s) in 420usr/0sys/426real ms.
parsed 'real_lookup' -> func 'real_lookup'
pattern 'kernel' matches module 'kernel'
focused on module 'kernel = [c0100000-c042ae14, bias 0] file
/usr/lib/debug/boot/vmlinux-2.6.18.2-34-default.debug ELF machine i686 (code
3)
pattern 'real_lookup' matches function 'real_lookup'
checking instances of inline real_lookup
examining inline instance of real_lookup
selected inline instance of real_lookup
querying entrypc c0170197 of instance of inline 'real_lookup'
probe real_lookup@fs/namei.c:447 kernel section=.text pc=0xc0170197
finding location for local 'parent' near address c0170197, module bias 0
finding location for local 'name' near address c0170197, module bias 0
pattern 'kernel' matches module 'kernel'
Eliding unused function print_regs
Eliding unused function print_backtrace
Eliding unused function backtrace
Eliding unused function pid
Eliding unused function ppid
Eliding unused function pexecname
Eliding unused function gid
Eliding unused function egid
Eliding unused function uid
Eliding unused function euid
Eliding unused function cpuid
Eliding unused function cpu
Eliding unused function print_stack
Eliding unused function pp
Eliding unused function probemod
Eliding unused function is_return
Eliding unused function target
Eliding unused function stp_pid
Eliding unused function stack_size
Eliding unused function stack_used
Eliding unused function stack_unused
Eliding unused function caller_addr
Eliding unused function caller
Eliding unused function user_string
Eliding unused function user_string2
Eliding unused function user_string_warn
Eliding unused function user_string_quoted
Eliding unused function get_cycles
Eliding unused function gettimeofday_ms
Eliding unused function gettimeofday_s
keeping expression identifier 'printf' at real_lookup.stp:7:2 because it
writes: _indent_counters _indent_timestamps and/or embedded: 1
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:5:6
because it writes: ts and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:6:56
because it writes: _indent_timestamps and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:9:5
because it writes: x and/or embedded: 0
keeping expression operator '+=' at
/usr/share/systemtap/tapset/indent.stp:10:25 because it writes:
_indent_counters and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:12:5
because it writes: r and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:14:9
because it writes: i and/or embedded: 0
keeping expression operator '++' at
/usr/share/systemtap/tapset/indent.stp:14:19 because it writes: i and/or
embedded: 0
keeping expression operator '.=' at
/usr/share/systemtap/tapset/indent.stp:14:25 because it writes: r and/or
embedded: 0
keeping expression identifier 'printf' at real_lookup.stp:7:2 because it
writes: _indent_counters _indent_timestamps and/or embedded: 1
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:5:6
because it writes: ts and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:6:56
because it writes: _indent_timestamps and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:9:5
because it writes: x and/or embedded: 0
keeping expression operator '+=' at
/usr/share/systemtap/tapset/indent.stp:10:25 because it writes:
_indent_counters and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:12:5
because it writes: r and/or embedded: 0
keeping expression operator '=' at /usr/share/systemtap/tapset/indent.stp:14:9
because it writes: i and/or embedded: 0
keeping expression operator '++' at
/usr/share/systemtap/tapset/indent.stp:14:19 because it writes: i and/or
embedded: 0
keeping expression operator '.=' at
/usr/share/systemtap/tapset/indent.stp:14:25 because it writes: r and/or
embedded: 0
semantic error: failed to retrieve location attribute for local 'name'
(dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
semantic error: failed to retrieve location attribute for local 'name'
(dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
semantic error: failed to retrieve location attribute for local 'name'
(dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
semantic error: failed to retrieve location attribute for local 'name'
(dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
Pass 2: analyzed script: 1 probe(s), 10 function(s), 1 embed(s), 2 global(s)
in 610usr/430sys/3166real ms.
Pass 2: analysis failed.  Try again with more '-v' (verbose) options.
Running rm -rf /tmp/stapABdKKf

So it seems that 'name' local is found but somehow it isn't able to handle
it. Besides that it is really strange that '$name' is of the same type than
'$parent->d_name' and which is actually found. 

Is this a bug?

Cheers,
Jan

Re: [BUG?] semantic error: failed to retrieve location attribute for local

[Frank Ch. Eigler]

Jan Blunck <jblunck@suse.de> writes:

> I have the following simple probe:
> probe kernel.inline("real_lookup")
> {
>         printf("%s - %s(%s): %s\n", thread_indent(0), probefunc(),
>                    kernel_string($parent->d_name->name),
>                    kernel_string($name->name))
> }

Welcome to the list!

> The full error message is as follows:
> [...]
> querying entrypc c0170197 of instance of inline 'real_lookup'
> probe real_lookup@fs/namei.c:447 kernel section=.text pc=0xc0170197
> finding location for local 'parent' near address c0170197, module bias 0
> finding location for local 'name' near address c0170197, module bias 0
> [...]
> semantic error: failed to retrieve location attribute for local 'name'
> (dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
> [...]
> Is this a bug?

Problems such as this tend to be limitations of gcc debugging
information quality.  One frequently-hit bug is that few actual
parameters get proper debugging information emitted, even if they are
used by the inlined function body.

- FChE

Re: [BUG?] semantic error: failed to retrieve location attribute for local

[Jan Blunck]

On Mon, Dec 04, Frank Ch. Eigler wrote:

> > The full error message is as follows:
> > [...]
> > querying entrypc c0170197 of instance of inline 'real_lookup'
> > probe real_lookup@fs/namei.c:447 kernel section=.text pc=0xc0170197
> > finding location for local 'parent' near address c0170197, module bias 0
> > finding location for local 'name' near address c0170197, module bias 0
> > [...]
> > semantic error: failed to retrieve location attribute for local 'name'
> > (dieoffset: 85127198053): identifier '$name' at real_lookup.stp:9:20
> > [...]
> > Is this a bug?
> 
> Problems such as this tend to be limitations of gcc debugging
> information quality.  One frequently-hit bug is that few actual
> parameters get proper debugging information emitted, even if they are
> used by the inlined function body.

This is a major problem. A lot of interesting code is inlined in the
kernel. Any plans/ideas how to fix this issue?

But the debuginfo is emitted AFAICS, isn't it?

 <1><6dd453>: Abbrev Number: 63 (DW_TAG_subprogram)
     DW_AT_sibling     : <6dd4b5>       
     DW_AT_name        : (indirect string, offset: 0x38365): real_lookup
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 447    
     DW_AT_prototyped  : 1      
     DW_AT_type        : <6d4e44>       
     DW_AT_inline      : 1      (inlined)
 <2><6dd465>: Abbrev Number: 61 (DW_TAG_formal_parameter)
     DW_AT_name        : (indirect string, offset: 0x8bfef): parent     
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 446    
     DW_AT_type        : <6d4e44>       
 <2><6dd471>: Abbrev Number: 61 (DW_TAG_formal_parameter)
     DW_AT_name        : (indirect string, offset: 0x43b44): name       
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 446    
     DW_AT_type        : <6d7bc9>       
 <2><6dd47d>: Abbrev Number: 50 (DW_TAG_formal_parameter)
     DW_AT_name        : nd     
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 446    
     DW_AT_type        : <6d7b2b>       
 <2><6dd488>: Abbrev Number: 51 (DW_TAG_variable)
     DW_AT_name        : (indirect string, offset: 0x38552): result     
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 448    
     DW_AT_type        : <6d4e44>       
 <2><6dd494>: Abbrev Number: 64 (DW_TAG_variable)
     DW_AT_name        : dir    
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 449    
     DW_AT_type        : <6d7851>       
 <2><6dd4a0>: Abbrev Number: 65 (DW_TAG_lexical_block)
     DW_AT_sibling     : <6dd4b3>       
 <3><6dd4a5>: Abbrev Number: 51 (DW_TAG_variable)
     DW_AT_name        : (indirect string, offset: 0x211b): dentry      
     DW_AT_decl_file   : 1      
     DW_AT_decl_line   : 468    
     DW_AT_type        : <6d4e44>       
 <3><6dd4b1>: Abbrev Number: 58 (DW_TAG_lexical_block)
 <2><6dd4b3>: Abbrev Number: 58 (DW_TAG_lexical_block)

Re: [BUG?] semantic error: failed to retrieve location attribute for local

[Frank Ch. Eigler]

Jan Blunck <jblunck@suse.de> writes:

> [...]
> > Problems such as this tend to be limitations of gcc debugging
> > information quality.  [...]
> This is a major problem. A lot of interesting code is inlined in the
> kernel. Any plans/ideas how to fix this issue?

In this case, one must spend some time hacking the compiler.

Once the marker-based static instrumentation widget makes it into the
official kernels, then sprinkling them into the more valuable inline
functions will let us hook up systemtap probes with no reliance on
debugging information.


> But the debuginfo is emitted AFAICS, isn't it?

Yes, some, but:

>  <1><6dd453>: Abbrev Number: 63 (DW_TAG_subprogram)
>      DW_AT_name        : (indirect string, offset: 0x38365): real_lookup [...]
>      DW_AT_inline      : 1      (inlined) [...]
>  <2><6dd471>: Abbrev Number: 61 (DW_TAG_formal_parameter)
>      DW_AT_name        : (indirect string, offset: 0x43b44): name       
>      DW_AT_decl_file   : 1      
>      DW_AT_decl_line   : 446    
>      DW_AT_type        : <6d7bc9>       
>  <2>[...]

Note that there is no DW_AT_location data, which we could use to
locate the values in memory/registers at run time.

- FChE

Re: [BUG?] semantic error: failed to retrieve location attribute for local

[Jan Blunck]

On Wed, Dec 06, Frank Ch. Eigler wrote:

> Once the marker-based static instrumentation widget makes it into the
> official kernels, then sprinkling them into the more valuable inline
> functions will let us hook up systemtap probes with no reliance on
> debugging information.

Ouch! My experience is that this doesn't really work for debugging purpose.
I bet the right marker is always missing when you need it most :(

> >  <1><6dd453>: Abbrev Number: 63 (DW_TAG_subprogram)
> >      DW_AT_name        : (indirect string, offset: 0x38365): real_lookup [...]
> >      DW_AT_inline      : 1      (inlined) [...]
> >  <2><6dd471>: Abbrev Number: 61 (DW_TAG_formal_parameter)
> >      DW_AT_name        : (indirect string, offset: 0x43b44): name       
> >      DW_AT_decl_file   : 1      
> >      DW_AT_decl_line   : 446    
> >      DW_AT_type        : <6d7bc9>       
> >  <2>[...]
> 
> Note that there is no DW_AT_location data, which we could use to
> locate the values in memory/registers at run time.

Hmm, yes. The DW_AT_location only exists for one of the paramters. Guess I'll
have to bug the gcc folks next door :)

Anyway, thanks a lot!