[Bug translator/5890] New: sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[Bug translator/5890] New: sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[wcohen at redhat dot com]

The systemtap tests fail when using the syscall.compat_sys_recvmsg and
syscall.compat_sys_sendmsg probes because the $fd argument cannot be found.
This problem can be seen with the rawhide kernels, 2.6.25-0.90.rc3.git5.fc9 on
x86_64 machine.

$ ./stap  ../systemtap/testsuite/systemtap.syscall/sys.stp 
semantic error: not accessible at this address: identifier '$fd' at
/home/wcohen/systemtap_write/install/share/systemtap/tapset/syscalls2.stp:766:33
semantic error: not accessible at this address: identifier '$fd' at
/home/wcohen/systemtap_write/install/share/systemtap/tapset/syscalls2.stp:1451:33
Pass 2: analysis failed.  Try again with more '-v' (verbose) options.

The problem functions are small wrappers, but they appear to be real functions
in linux/net/compat.c:

asmlinkage long compat_sys_sendmsg(int fd, struct compat_msghdr __user *msg,
unsigned flags)
{
        return sys_sendmsg(fd, (struct msghdr __user *)msg, flags |
MSG_CMSG_COMPAT);
}

asmlinkage long compat_sys_recvmsg(int fd, struct compat_msghdr __user *msg,
unsigned int flags)
{
        return sys_recvmsg(fd, (struct msghdr __user *)msg, flags |
MSG_CMSG_COMPAT);
}



This might be due to the translator not finding the $fd or missing debugging
information. All the syscall tests fail on fedora 9 x86_64 machine.

-- 
           Summary: sys.stp andtestsuite/systemtap.syscall/sys.stp fail on
                    2.6.25 x86_64
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: translator
        AssignedTo: systemtap at sources dot redhat dot com
        ReportedBy: wcohen at redhat dot com


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[fche at redhat dot com]

------- Additional Comments From fche at redhat dot com  2008-03-05 20:11 -------
Is there any reason to believe that this is not just an
ordinary duplicate of the "no debuginfo generated for
inlined function parameters/locals" bug #1155?


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[wcohen at redhat dot com]

------- Additional Comments From wcohen at redhat dot com  2008-03-05 22:09 -------
The debug information has some information about fd.

$ pfunct --function=compat_sys_sendmsg
/usr/lib/debug/lib/modules/2.6.25-0.90.rc3.git5.fc9/vmlinux
long int compat_sys_sendmsg(int fd, struct compat_msghdr * msg, unsigned int flags);

There the probe is being places might not have the fd variable available.

ffffffff8122db3b <compat_sys_sendmsg>:
ffffffff8122db3b:	55                   	push   %rbp
ffffffff8122db3c:	81 ca 00 00 00 80    	or     $0x80000000,%edx
ffffffff8122db42:	48 89 e5             	mov    %rsp,%rbp
ffffffff8122db45:	e8 7c 4d fe ff       	callq  ffffffff812128c6 <sys_sendmsg>
ffffffff8122db4a:	c9                   	leaveq 
ffffffff8122db4b:	c3                   	retq   

Removed the accesses to $fd in script probing problem functions to see where
kprobes are being place.

./stap -k  -D DEBUG_SYMBOLS  /tmp/f9_sys_failsa.stp

_stp_do_symbols:264: Got kernel symbols. text=0xffffffff81009000 len=2754847
...
_stp_module_relocate:36: kernel, _stext, 22516f
_stp_module_relocate:36: kernel, _stext, 225181


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[mjw at redhat dot com]

------- Additional Comments From mjw at redhat dot com  2008-11-03 10:30 -------
Same issue for trying to access $return in compat_sys_recvmsg:

$ /usr/local/systemtap/bin/stap -v -e 'probe syscall.*.return { printf("%s =>
%d\n", probefunc(), $return)}'
Pass 1: parsed user script and 46 library script(s) in 230usr/10sys/252real ms.
semantic error: unable to find return value near pc 0xffffffff8122a292 for
compat_sys_recvmsg(net/compat.c): identifier '$return' at <input>:1:60
        source: probe syscall.*.return { printf("%s => %d\n", probefunc(), $return)}
                                                                           ^
Pass 2: analyzed script: 395 probe(s), 394 function(s), 14 embed(s), 0 global(s)
in 3090usr/480sys/3596real ms.
Pass 2: analysis failed.  Try again with more '-v' (verbose) options.


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[jistone at redhat dot com]

------- Additional Comments From jistone at redhat dot com  2009-04-13 22:07 -------
For the original problem report, I can reproduce the $fd failures on builds from
a year ago, but not on the current tree.  For the $return failure, it should now
work as part of my fix for bug #10049.  Please check and report whether this is
still a problem for you.

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |WAITING


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[wcohen at redhat dot com]

------- Additional Comments From wcohen at redhat dot com  2009-04-14 13:36 -------
Tried this out on a x86_64 f9 machine running 2.6.27.21-78.2.41.fc9.x86_64. Both
the tests in the description and comment #3 work.

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|WAITING                     |RESOLVED
         Resolution|                            |FIXED


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[przemyslaw at pawelczyk dot it]

------- Additional Comments From przemyslaw at pawelczyk dot it  2009-10-09 00:11 -------
Unfortunately, the one who fixed it is also the one who broke it.


Since:
b74789646bfe59131327716357c8b7c  PR10572: Allow duplicate function names in a CU

we have:
$ stap -ve 'probe syscall.compat_sys_recvmsg { println($fd); }'
Pass 1: parsed user script and 59 library script(s) in 340usr/20sys/369real ms.
semantic error: not accessible at this address: identifier '$fd' at <input>:1:44
        source: probe syscall.compat_sys_recvmsg { println($fd); }
                                                           ^
Pass 2: analyzed script: 2 probe(s), 1 function(s), 14 embed(s), 0 global(s) in
720usr/120sys/828real ms.
Pass 2: analysis failed.  Try again with another '--vp 01' option.


Josh, introducing status quo here is a really bad idea. ;)

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |REOPENED
         Resolution|FIXED                       |


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[jistone at redhat dot com]

------- Additional Comments From jistone at redhat dot com  2009-10-09 02:56 -------
(In reply to comment #6)
> Unfortunately, the one who fixed it is also the one who broke it.
> [...]
> Josh, introducing status quo here is a really bad idea. ;)

I'll take full responsibility, of course. :)  What kernel is this?  On my
2.6.30.8-64.fc11.x86_64 it works fine.

It's possible that this is (unfortunately) correct.  Commit b7478964 was made to
discover cases where a function exists multiple times in a CU.  For example, an
extern function might be generated normally, but then also inlined somewhere
within the same file.  Or, a single function might get multiple generated
outputs with different optimizations.

My guess is that on your kernel has multiple copies of compat_sys_recvmsg.  It's
just a shallow wrapper for sys_recvmsg, so I wouldn't be surprised if the call
in compat_sys_socketcall is inlined.  It's not static though, so the compiler
would still need to generate a full function output too.

That it worked before b7478964 might be just because the full copy with an
accessible $fd was shadowing the inline where $fd is less accessible.  If this
is the case, then I think our failure here is actually insufficient debuginfo
(bug #1155), and the previous success was wrong.

Anyway, I'm just guessing, so let's check what is actually the case.  Please try
with more -v and see where the probe is actually being resolved.

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|REOPENED                    |WAITING


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[przemyslaw at pawelczyk dot it]

------- Additional Comments From przemyslaw at pawelczyk dot it  2009-10-09 09:14 -------
(In reply to comment #7)
> I'll take full responsibility, of course. :)  What kernel is this?  On my
> 2.6.30.8-64.fc11.x86_64 it works fine.

I'm using customized kernel 2.6.27.24 (with debuginfo) on debian x86_64.

> That it worked before b7478964 might be just because the full copy with an
> accessible $fd was shadowing the inline where $fd is less accessible.  If this
> is the case, then I think our failure here is actually insufficient debuginfo
> (bug #1155), and the previous success was wrong.
> 
> Anyway, I'm just guessing, so let's check what is actually the case.  Please try
> with more -v and see where the probe is actually being resolved.

$ stap --vp 03 -e 'probe syscall.compat_sys_recvmsg { println($fd); }'
...
parsed 'compat_sys_recvmsg', func 'compat_sys_recvmsg'
focused on module 'kernel = [0xffffffff80200000-0xffffffff8075a1e4, bias 0x0] file /boot/vmlinux-2.6.27.24-kp+di ELF machine |x86_64 (code 62)
focused on module 'kernel'
selected inline instance of compat_sys_recvmsg
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c4f69) = 0xffffffff8048a9a4 (rc 0)
selected function compat_sys_recvmsg
probe compat_sys_recvmsg@net/compat.c:737 kernel reloc=.dynamic pc=0xffffffff80489d5b
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c38d2) = 0xffffffff80489d5b (rc 0)
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'msg' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'flags' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'msg' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'flags' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
querying entrypc ffffffff8048a9a4 of instance of inline 'compat_sys_recvmsg'
probe compat_sys_recvmsg@net/compat.c:737 kernel reloc=.dynamic pc=0xffffffff8048a9a4
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c4f69) = 0xffffffff8048a9a4 (rc 0)
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'msg' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'flags' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'msg' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'flags' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
parsed 'compat_sys_recvmsg', func 'compat_sys_recvmsg'
focused on module 'kernel = [0xffffffff80200000-0xffffffff8075a1e4, bias 0x0] file /boot/vmlinux-2.6.27.24-kp+di ELF machine |x86_64 (code 62)
focused on module 'kernel'
selected inline instance of compat_sys_recvmsg
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c4f69) = 0xffffffff8048a9a4 (rc 0)
selected function compat_sys_recvmsg
probe compat_sys_recvmsg@net/compat.c:737 kernel reloc=.dynamic pc=0xffffffff80489d5b
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c38d2) = 0xffffffff80489d5b (rc 0)
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'msg' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'flags' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'msg' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'flags' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
finding location for local 'fd' near address 0xffffffff80489d5b, module bias 0x0
get_cfa_ops @0xffffffff80489d5b, module_start @0xffffffff80200000
not found cfa
querying entrypc ffffffff8048a9a4 of instance of inline 'compat_sys_recvmsg'
probe compat_sys_recvmsg@net/compat.c:737 kernel reloc=.dynamic pc=0xffffffff8048a9a4
entry-pc lookup (dwarf_entrypc dieoffset: 0x25c4f69) = 0xffffffff8048a9a4 (rc 0)
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'msg' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'flags' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'msg' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'flags' near address 0xffffffff8048a9a4, module bias 0x0
finding location for local 'fd' near address 0xffffffff8048a9a4, module bias 0x0
...  [Eliding unused function ...]
...  [Eliding assignment to ...]
...  [Eliding side-effect-free ...]
Eliding unused function _dwarf_tvar_get_fd_0
Eliding unused function _dwarf_tvar_get_fd_3
Eliding unused function _dwarf_tvar_get_flags_2
Eliding unused function _dwarf_tvar_get_flags_5
Eliding unused function _dwarf_tvar_get_msg_1
Eliding unused function _dwarf_tvar_get_msg_4
Eliding unused function _recvflags_str
Eliding unused function strlen
Eliding unused function substr
Eliding unused local variable name in probe_1845
Eliding unused local variable s in probe_1845
Eliding unused local variable msg_uaddr in probe_1845
Eliding unused local variable flags in probe_1845
Eliding unused local variable argstr in probe_1845
Eliding unused local variable name in probe_1846
Eliding unused local variable s in probe_1846
Eliding unused local variable msg_uaddr in probe_1846
Eliding unused local variable flags in probe_1846
Eliding unused local variable argstr in probe_1846
Resolution problem with probe probe_1846
println($fd)
semantic error: not accessible at this address (0xffffffff8048a9a4): identifier '$fd' at <input>:1:44
        source: probe syscall.compat_sys_recvmsg { println($fd); }
                                                           ^
...


Should I provide any other information?

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[jistone at redhat dot com]

------- Additional Comments From jistone at redhat dot com  2009-10-09 17:48 -------
(In reply to comment #8)
> selected inline instance of compat_sys_recvmsg
> entry-pc lookup (dwarf_entrypc dieoffset: 0x25c4f69) = 0xffffffff8048a9a4 (rc 0)
> selected function compat_sys_recvmsg
> probe compat_sys_recvmsg@net/compat.c:737 kernel reloc=.dynamic
pc=0xffffffff80489d5b
> entry-pc lookup (dwarf_entrypc dieoffset: 0x25c38d2) = 0xffffffff80489d5b (rc 0)

So I was right -- there's an inline and a full function.

> semantic error: not accessible at this address (0xffffffff8048a9a4):
identifier '$fd' at <input>:1:44
>         source: probe syscall.compat_sys_recvmsg { println($fd); }

And it is the inline that can't find $fd.  This is correct, in that we're doing
the best we can with bad debuginfo... :(

Since this is your own kernel, you could just patch that function with
attribute-noinline, or even compile with a VTA-enabled gcc to get better
tracking of inline vars.

This also makes me think that the syscall tapset is slightly broken.  We have
.return variants for almost all of them, but that can only work when they're not
inlined, so perhaps these should all be .call probes.  We would also probably
want syscall.socketcall enabled then, to cover this particular example that
could be inlined...

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug translator/5890] sys.stp andtestsuite/systemtap.syscall/sys.stp fail on 2.6.25 x86_64

[przemyslaw at pawelczyk dot it]

------- Additional Comments From przemyslaw at pawelczyk dot it  2009-10-13 14:23 -------
As Josh suggested, .call solves the problem I mentioned in comment #6.

Commit:
9a59aed Add the .call modifier to syscall entry probes.

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|WAITING                     |RESOLVED
         Resolution|                            |FIXED


http://sourceware.org/bugzilla/show_bug.cgi?id=5890

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.