Concurrent userspace probes targeting same location

Concurrent userspace probes targeting same location

[Wade Farnsworth]

Greetings,

I'm seeing some odd behavior when multiple userspace return probes are 
running attached to the same target location.

First, the return value of uaddr() of one probe points to a location 
inside of the second.  The second probe's uaddr() behaves as expected.

Second, it appears that occasionally a probe will get executed twice for 
a specific function return.

I have observed these problems on x86/Fedora 16, and ARM/Yocto.

Here are some sample probes that exhibit the problems:

probe process("/bin/ls").library("libc.so.6").function("malloc").return
{
     if (usymname(uaddr()) == "__libc_malloc")
         next;
     printf("malloc probe 1 -- ptr: 0x%x, return addr 0x%x\n", $return, 
uaddr());
}

probe process("/bin/ls").library("libc.so.6").function("malloc").return
{
     if (usymname(uaddr()) == "__libc_malloc")
         next;
     printf("malloc probe 2 -- ptr: 0x%x, return addr 0x%x\n", $return, 
uaddr());
}

And here is a snippet of the output when these are run simultaneously on 
Fedora 16:

malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
malloc probe 1 -- ptr: 0x9b12008, return addr 0x446f1901
malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
malloc probe 1 -- ptr: 0x9b12020, return addr 0x4469f1fc
malloc probe 2 -- ptr: 0x9b12030, return addr 0xbfcbe010
malloc probe 1 -- ptr: 0x9b12030, return addr 0x44698da2
malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
...

The lines prefixed with "malloc probe 2" consistently point into the 
kernel module space (0xbfcbe010), instead of into userspace.  Also, the 
first two lines demonstrate the double execution problem (note the 
identical values of $return).

Has anyone experienced anything similar?  Is this even a valid use case?

Thanks,

Wade

Re: Concurrent userspace probes targeting same location

[David Smith]

On 07/03/2012 03:06 PM, Wade Farnsworth wrote:
> Greetings,
> 
> I'm seeing some odd behavior when multiple userspace return probes are
> running attached to the same target location.
> 
> First, the return value of uaddr() of one probe points to a location
> inside of the second.  The second probe's uaddr() behaves as expected.
> 
> Second, it appears that occasionally a probe will get executed twice for
> a specific function return.
> 
> I have observed these problems on x86/Fedora 16, and ARM/Yocto.
> 
> Here are some sample probes that exhibit the problems:
> 
> probe process("/bin/ls").library("libc.so.6").function("malloc").return
> {
>     if (usymname(uaddr()) == "__libc_malloc")
>         next;
>     printf("malloc probe 1 -- ptr: 0x%x, return addr 0x%x\n", $return,
> uaddr());
> }
> 
> probe process("/bin/ls").library("libc.so.6").function("malloc").return
> {
>     if (usymname(uaddr()) == "__libc_malloc")
>         next;
>     printf("malloc probe 2 -- ptr: 0x%x, return addr 0x%x\n", $return,
> uaddr());
> }
> 
> And here is a snippet of the output when these are run simultaneously on
> Fedora 16:

When you say "run simultaneously", do you mean run as two separate
scripts at the same time or run in the same script?

> malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
> malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
> malloc probe 1 -- ptr: 0x9b12008, return addr 0x446f1901
> malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
> malloc probe 1 -- ptr: 0x9b12020, return addr 0x4469f1fc
> malloc probe 2 -- ptr: 0x9b12030, return addr 0xbfcbe010
> malloc probe 1 -- ptr: 0x9b12030, return addr 0x44698da2
> malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
> ...
> 
> The lines prefixed with "malloc probe 2" consistently point into the
> kernel module space (0xbfcbe010), instead of into userspace.  Also, the
> first two lines demonstrate the double execution problem (note the
> identical values of $return).
> 
> Has anyone experienced anything similar?  Is this even a valid use case?

Running multiple return probes at the same location in the same script
should work.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: Concurrent userspace probes targeting same location

[Wade Farnsworth]

David Smith wrote:
> On 07/03/2012 03:06 PM, Wade Farnsworth wrote:
>> Greetings,
>>
>> I'm seeing some odd behavior when multiple userspace return probes are
>> running attached to the same target location.
>>
>> First, the return value of uaddr() of one probe points to a location
>> inside of the second.  The second probe's uaddr() behaves as expected.
>>
>> Second, it appears that occasionally a probe will get executed twice for
>> a specific function return.
>>
>> I have observed these problems on x86/Fedora 16, and ARM/Yocto.
>>
>> Here are some sample probes that exhibit the problems:
>>
>> probe process("/bin/ls").library("libc.so.6").function("malloc").return
>> {
>>      if (usymname(uaddr()) == "__libc_malloc")
>>          next;
>>      printf("malloc probe 1 -- ptr: 0x%x, return addr 0x%x\n", $return,
>> uaddr());
>> }
>>
>> probe process("/bin/ls").library("libc.so.6").function("malloc").return
>> {
>>      if (usymname(uaddr()) == "__libc_malloc")
>>          next;
>>      printf("malloc probe 2 -- ptr: 0x%x, return addr 0x%x\n", $return,
>> uaddr());
>> }
>>
>> And here is a snippet of the output when these are run simultaneously on
>> Fedora 16:
>
> When you say "run simultaneously", do you mean run as two separate
> scripts at the same time or run in the same script?

I encounter the problems in both situations.  Whether the probes are in 
separate scripts/stap instances or the same one, it doesn't seem to make 
a difference.

>
>> malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
>> malloc probe 2 -- ptr: 0x9b12008, return addr 0xbfcbe010
>> malloc probe 1 -- ptr: 0x9b12008, return addr 0x446f1901
>> malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
>> malloc probe 1 -- ptr: 0x9b12020, return addr 0x4469f1fc
>> malloc probe 2 -- ptr: 0x9b12030, return addr 0xbfcbe010
>> malloc probe 1 -- ptr: 0x9b12030, return addr 0x44698da2
>> malloc probe 2 -- ptr: 0x9b12020, return addr 0xbfcbe010
>> ...
>>
>> The lines prefixed with "malloc probe 2" consistently point into the
>> kernel module space (0xbfcbe010), instead of into userspace.  Also, the
>> first two lines demonstrate the double execution problem (note the
>> identical values of $return).
>>
>> Has anyone experienced anything similar?  Is this even a valid use case?
>
> Running multiple return probes at the same location in the same script
> should work.
>

Re: Concurrent userspace probes targeting same location

[David Smith]

On 07/03/2012 04:37 PM, Wade Farnsworth wrote:
> David Smith wrote:
>> Running multiple return probes at the same location in the same script
>> should work.

I've duplicated your problem.  This is quite odd, especially since both
probes are getting inserted at the exact same address (0x8x520), as
shown by the following "stap -p2" output:

# stap -p2 -d /bin/ls ../ls_malloc.stp -c ls | more
...
# probes
process("/lib64/libc-2.14.90.so").function("__libc_malloc@/usr/src/debug/glibc-2.14-394-g8f3b1ff/malloc/malloc.c:2913").return?
/* pc=.dynamic+0x82520 */ /* <-
process("/bin/ls").library("libc.so.6").function("malloc").return? =
process("/bin/ls").library("/lib64/libc-2.14.90.so").function("malloc").return?
<- process("/bin/ls").library("libc.so.6").function("malloc").return */
process("/lib64/libc-2.14.90.so").function("__libc_malloc@/usr/src/debug/glibc-2.14-394-g8f3b1ff/malloc/malloc.c:2913").return?
/* pc=.dynamic+0x82520 */ /* <-
process("/bin/ls").library("libc.so.6").function("malloc").return? =
process("/bin/ls").library("/lib64/libc-2.14.90.so").function("malloc").return?
<- process("/bin/ls").library("libc.so.6").function("malloc").return */

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: Concurrent userspace probes targeting same location

[Frank Ch. Eigler]

wade_farnsworth wrote:

> [...]  I have observed these problems on x86/Fedora 16, and
> ARM/Yocto. [...]

Sounds like a uprobes (ie. systemtap/runtime/uprobes*) bug.

- FChE