Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Lluís Vilanova]

Frank Ch Eigler writes:

> Hi, Lluís -
>> I've attached both. BTW, I'm using debian's gcc 6.1.1-1.

> Thank you.  Those both look just fine, argh.  Could you try using
> gdb's "static probe points" facility to break at the same point, to
> see if the arguments are accessible?

> https://sourceware.org/gdb/onlinedocs/gdb/Static-Probe-Points.html

> Maybe provide a disassembly of the two functions of that binary, just
> to confirm that the numeric parameters are being passed?

Everything seems correct (gdb 7.11.1-2), so either the kernel or systemtap are
garbling up the arguments when retrieving them, or systemtap gets confused and
gets them from the wrong place.

$ gdb ./test
(gdb) break main
(gdb) run
Starting program: /home/lluis/tmp/systemtap/test 

Breakpoint 3, main (argc=1, argv=0x7fffe168) at test.c:12
12  f(1, 1);

# just in case, I made sure the program is loaded

(gdb) disassemble main
Dump of assembler code for function main:
   0x0040050f <+0>: push   %rbp
   0x00400510 <+1>: mov%rsp,%rbp
   0x00400513 <+4>: sub$0x10,%rsp
   0x00400517 <+8>: mov%edi,-0x4(%rbp)
   0x0040051a <+11>:mov%rsi,-0x10(%rbp)
=> 0x0040051e <+15>:mov$0x1,%esi
   0x00400523 <+20>:mov$0x1,%edi
   0x00400528 <+25>:callq  0x4004e6 
   0x0040052d <+30>:mov$0x2,%esi
   0x00400532 <+35>:mov$0x2,%edi
   0x00400537 <+40>:callq  0x4004e6 
   0x0040053c <+45>:mov$0x0,%eax
   0x00400541 <+50>:leaveq 
   0x00400542 <+51>:retq   
(gdb) disassemble f
Dump of assembler code for function f:
   0x004004e6 <+0>: push   %rbp
   0x004004e7 <+1>: mov%rsp,%rbp
   0x004004ea <+4>: sub$0x10,%rsp
   0x004004ee <+8>: mov%edi,-0x4(%rbp)
   0x004004f1 <+11>:mov%esi,-0x8(%rbp)
   0x004004f4 <+14>:nop
   0x004004f5 <+15>:mov-0x8(%rbp),%edx
   0x004004f8 <+18>:mov-0x4(%rbp),%eax
   0x004004fb <+21>:mov%eax,%esi
   0x004004fd <+23>:mov$0x4005d4,%edi
   0x00400502 <+28>:mov$0x0,%eax
   0x00400507 <+33>:callq  0x4003c0 
   0x0040050c <+38>:nop
   0x0040050d <+39>:leaveq 
   0x0040050e <+40>:retq   
(gdb) info probes
Type Provider Name Where  Semaphore  Object 

stap test f0x004004f4 0x00600988 
/home/lluis/tmp/systemtap/test 
(gdb) enable probes test
Probe test:f cannot be enabled.
(gdb) b -probe test:f
Breakpoint 1 at 0x4004f4
(gdb) info b
Num Type   Disp Enb AddressWhat
1   breakpoint keep y   0x004004f4 -probe test:f
(gdb) c
Continuing.

Breakpoint 1, f (a1=1, a2=1) at test.c:6
6   TEST_F(a1, a2);
(gdb) p $rsi
$1 = 1
(gdb) p $rdi
$2 = 1
(gdb) c
Continuing.
a1=1 a2=1

Breakpoint 1, f (a1=2, a2=2) at test.c:6
6   TEST_F(a1, a2);
(gdb) p $rsi
$3 = 2
(gdb) p $rdi
$4 = 2
(gdb) c
Continuing.
a1=2 a2=2
[Inferior 1 (process 30372) exited normally]


Thanks,
  Lluis

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Frank Ch. Eigler]

Hi, Lluís -


> I've attached both. BTW, I'm using debian's gcc 6.1.1-1.

Thank you.  Those both look just fine, argh.  Could you try using
gdb's "static probe points" facility to break at the same point, to
see if the arguments are accessible?

https://sourceware.org/gdb/onlinedocs/gdb/Static-Probe-Points.html

Maybe provide a disassembly of the two functions of that binary, just
to confirm that the numeric parameters are being passed?

- FChE

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Lluís Vilanova]

Frank Ch Eigler writes:

> Hi -
>> $ cat >test.c <<\EOF
>> [...]
>> int f(int a1, int a2)
>> {
>> TEST_F(a1, a2);
>> [...]
>> }
>> 
>> int main(int argc, char *argv[])
>> {
>> f(1, 1);
>> f(2, 2);
>> return 0;
>> }
>> EOF
>> [...]
>> $ gcc -o test -O0 -g test.c events.o
>> $ sudo stap test.stp -c './test'
>> [...]
>> 0 0
>> 0 0

> It would be interesting to see the "stap -p3" output for that test
> script, and/or the "readelf -n ./test", so we could tell what kind of
> operands the compiler generated for those two arguments.

I've attached both. BTW, I'm using debian's gcc 6.1.1-1.

Cheers,
  Lluis



stap-p3
Description: Binary data


readelf-n
Description: Binary data

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Lluís Vilanova]

Vincent Bernat writes:

>  ❦ 13 septembre 2016 19:10 CEST, Lluís Vilanova  :
>> Hi! I've been writing some very simple systemtap scripts, and printing the
>> values of arguments to user-defined probe marks always shows zeroes.
>> 
>> Here's an minimal failing example:
>> 
>> $ cat >events.d <<\EOF
>> provider test
>> {
>> probe f(int a1, int a2);
>> };
>> EOF
>> 
>> $ cat >test.c <<\EOF
>> #include 
>> #include "events.h"
>> 
>> int f(int a1, int a2)
>> {
>> TEST_F(a1, a2);
>> printf("a1=%d a2=%d\n", a1, a2);
>> }
>> 
>> int main(int argc, char *argv[])
>> {
>> f(1, 1);
>> f(2, 2);
>> return 0;
>> }
>> EOF
>> 
>> $ dtrace -s events.d -G
>> $ dtrace -s events.d -h
>> $ gcc -o test -O0 -g test.c events.o
>> $ sudo stap test.stp -c './test'
>> a1=1 a2=1
>> a1=2 a2=2
>> hello
>> 0 0
>> 0 0

> You didn't provide the test.stp script. I suppose this is something like:

> probe process.begin {
>   printf("hello\n");
> }
> probe process("./test").mark("f") {
>   printf("%d %d\n", $arg1, $arg2);
> }

That's exactly it, sorry.


>> Bug #691167 should no longer be applicable, since I'm running a stock debian
>> kernel (4.7) with UPROBES enabled:

> It's odd that you succeed in compiling anything with 4.7 as it needs a
> patch to work. I am uploading an updated version with this patch:
>  
> https://sourceware.org/git/gitweb.cgi?p=systemtap.git;a=commitdiff;h=8f888904d8de9a798e4664caa373ea552366b304;hp=79be36dbc39d25270261b857e51edbc198f204d7

> With this patch applied, I can compile your example and I get:

> a1=1 a2=1
> a1=2 a2=2
> hello
> hello
> 1 1
> 2 2

Sorry, I said 4.7 from the top of my head, but I was in fact testing with
debian's 4.6. But I do remember patching "transport.c" to compile scripts with
my locally built 4.8.0-rc5 (same patch needed for 4.7).

I just re-tested with 4.6 and it's failing. I also re-checked my local
"transport.c" patch (I'm checking against LINUX_VERSION_CODE) and re-tested with
debian's 4.7, and I'm still getting the "all zeroes" error.


Thanks,
  Lluis

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Frank Ch. Eigler]

Hi -

> $ cat >test.c <<\EOF
> [...]
> int f(int a1, int a2)
> {
> TEST_F(a1, a2);
> [...]
> }
> 
> int main(int argc, char *argv[])
> {
> f(1, 1);
> f(2, 2);
> return 0;
> }
> EOF
> [...]
> $ gcc -o test -O0 -g test.c events.o
> $ sudo stap test.stp -c './test'
> [...]
> 0 0
> 0 0

It would be interesting to see the "stap -p3" output for that test
script, and/or the "readelf -n ./test", so we could tell what kind of
operands the compiler generated for those two arguments.

- FChE

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Vincent Bernat]

 ❦ 13 septembre 2016 19:10 CEST, Lluís Vilanova  :

> Hi! I've been writing some very simple systemtap scripts, and printing the
> values of arguments to user-defined probe marks always shows zeroes.
>
> Here's an minimal failing example:
>
> $ cat >events.d <<\EOF
> provider test
> {
> probe f(int a1, int a2);
> };
> EOF
>
> $ cat >test.c <<\EOF
> #include 
> #include "events.h"
>
> int f(int a1, int a2)
> {
> TEST_F(a1, a2);
> printf("a1=%d a2=%d\n", a1, a2);
> }
>
> int main(int argc, char *argv[])
> {
> f(1, 1);
> f(2, 2);
> return 0;
> }
> EOF
>
> $ dtrace -s events.d -G
> $ dtrace -s events.d -h
> $ gcc -o test -O0 -g test.c events.o
> $ sudo stap test.stp -c './test'
> a1=1 a2=1
> a1=2 a2=2
> hello
> 0 0
> 0 0

You didn't provide the test.stp script. I suppose this is something like:

probe process.begin {
  printf("hello\n");
}
probe process("./test").mark("f") {
  printf("%d %d\n", $arg1, $arg2);
}

> Bug #691167 should no longer be applicable, since I'm running a stock debian
> kernel (4.7) with UPROBES enabled:

It's odd that you succeed in compiling anything with 4.7 as it needs a
patch to work. I am uploading an updated version with this patch:
 
https://sourceware.org/git/gitweb.cgi?p=systemtap.git;a=commitdiff;h=8f888904d8de9a798e4664caa373ea552366b304;hp=79be36dbc39d25270261b857e51edbc198f204d7

With this patch applied, I can compile your example and I get:

a1=1 a2=1
a1=2 a2=2
hello
hello
1 1
2 2
-- 
Use variable names that mean something.
- The Elements of Programming Style (Kernighan & Plauger)


signature.asc
Description: PGP signature

Bug#837697: systemtap: Arguments of user probes are always (incorrectly) zero

[Lluís Vilanova]

Package: systemtap
Version: 3.0-6
Severity: normal

Hi! I've been writing some very simple systemtap scripts, and printing the
values of arguments to user-defined probe marks always shows zeroes.

Here's an minimal failing example:

$ cat >events.d <<\EOF
provider test
{
probe f(int a1, int a2);
};
EOF

$ cat >test.c <<\EOF
#include 
#include "events.h"

int f(int a1, int a2)
{
TEST_F(a1, a2);
printf("a1=%d a2=%d\n", a1, a2);
}

int main(int argc, char *argv[])
{
f(1, 1);
f(2, 2);
return 0;
}
EOF

$ dtrace -s events.d -G
$ dtrace -s events.d -h
$ gcc -o test -O0 -g test.c events.o
$ sudo stap test.stp -c './test'
a1=1 a2=1
a1=2 a2=2
hello
0 0
0 0


While the printf's show correct values for a1 and a2, the stap script always
shows zeroes. Executing as a regular use (on the stapdev and stapusr groups)
shows the same errors.

Bug #691167 should no longer be applicable, since I'm running a stock debian
kernel (4.7) with UPROBES enabled:

$ grep UPROBES /boot/config-*
/boot/config-3.16.0-4-amd64:CONFIG_ARCH_SUPPORTS_UPROBES=y
/boot/config-3.16.0-4-amd64:CONFIG_UPROBES=y
/boot/config-4.6.0-1-amd64:CONFIG_ARCH_SUPPORTS_UPROBES=y
/boot/config-4.6.0-1-amd64:CONFIG_UPROBES=y
/boot/config-4.7.0-1-amd64:CONFIG_ARCH_SUPPORTS_UPROBES=y
/boot/config-4.7.0-1-amd64:CONFIG_UPROBES=y
/boot/config-4.8.0-rc5:CONFIG_ARCH_SUPPORTS_UPROBES=y
/boot/config-4.8.0-rc5:CONFIG_UPROBES=y

I've also tried to compile the latest linux kernel version (4.8.0-rc5, vanilla
upstream) and the failure is still the same.



Thanks,
  Lluis


-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (990, 'testing'), (500, 'stable-updates'), (500, 'unstable'), 
(500, 'stable'), (250, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.8.0-rc5 (SMP w/4 CPU cores)
Locale: LANG=ca_ES.UTF-8, LC_CTYPE=ca_ES.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages systemtap depends on:
ii  libavahi-client3   0.6.32-1
ii  libavahi-common3   0.6.32-1
ii  libc6  2.23-5
ii  libdw1 0.166-2
ii  libelf10.166-2
ii  libgcc11:6.1.1-11
ii  libnspr4   2:4.12-2
ii  libnss32:3.25-1
ii  libsqlite3-0   3.14.1-1
ii  libstdc++6 6.1.1-11
ii  make   4.1-9
ii  systemtap-common   3.0-6
ii  systemtap-runtime  3.0-6

systemtap recommends no packages.

Versions of packages systemtap suggests:
pn  systemtap-doc  
pn  vim-addon-manager  

-- no debconf information