lkml.org 
[lkml]   [2016]   [Aug]   [25]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
Subject[BUG] perf tool: uprobe displays wrong argument value
hi,
Michael reported wrong values for function arguments being shown
when adding uprobe on function with argument, I dig in and got
even more confused.. ;-)

This is the testing binary:

---
#include <stdio.h>

int func(int par)
{
return par;
}

int main(void)
{
int a = 1;
return func(a);
}
---

Adding the uprobe:

# ./perf probe -x ./ex --add 'func par'
Added new event:
probe_ex:func (on func in /home/jolsa/linux-perf/tools/perf/ex with par)

You can now use it in all perf tools, such as:

perf record -e probe_ex:func -aR sleep 1

Enabling globaly:
# echo 1 > events/probe_ex/func/enable


After running the binary, this is the 'trace' output:
# cat trace
...
ex-15942 [014] d... 371.608516: func: (0x4004f6) par=0

Same with perf record:
# ./perf record -e probe_ex:func -aR ./ex
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.157 MB perf.data (1 samples) ]
# ./perf script
ex 15954 [017] 489.298178: probe_ex:func: (4004f6) par=0


So, there's clearly bug in there..


Now here's where I got confused.. please continue reading only on your own risk ;-)

The uprobe_events shows following record:
# cat uprobe_events
p:probe_ex/func /home/jolsa/linux-perf/tools/perf/ex:0x00000000000004f6 par=-12(%sp):s32

I can't see how ($rsp - 12) address could hold the 'par' value,
when we stop at the 'func' addreess, so where did it come from?

I figured it's the debug info, namely the par argument's CU:

$ readelf --debug-dump ./ex | less
...

<2><94>: Abbrev Number: 5 (DW_TAG_formal_parameter)
<95> DW_AT_name : par
<99> DW_AT_decl_file : 1
<9a> DW_AT_decl_line : 3
<9b> DW_AT_type : <0x57>
<9f> DW_AT_location : 2 byte block: 91 6c (DW_OP_fbreg: -20)

which says the value is frame buffer reg -20.. I can't see
this will get the proper value for any of $rbp or $rsp even
after new func's stack frame is set..

Also if I set gdb to stop directly on the function address,
it shows wrong value:

# gdb ./ex
(gdb) b *0x4004f6
Breakpoint 1 at 0x4004f6: file ex.c, line 4.
(gdb) r
Starting program: /home/jolsa/linux-perf/tools/perf/ex
Missing separate debuginfos, use: dnf debuginfo-install glibc-2.21-13.fc22.x86_64

Breakpoint 1, func (par=0) at ex.c:4
4 {
(gdb)

Apart from when I set the breakpoint after the new stack frame is set:

(gdb) b func
Breakpoint 1 at 0x4004fd: file ex.c, line 5.
(gdb) r
Starting program: /home/jolsa/linux-perf/tools/perf/ex
Missing separate debuginfos, use: dnf debuginfo-install glibc-2.21-13.fc22.x86_64

Breakpoint 1, func (par=1) at ex.c:5
5 return par;


I'm clearly missing something..

thanks for help,
jirka


---
kernel version: 4.8.0-rc2
perf version: latest Arnaldo's perf/core

\
 
 \ /
  Last update: 2016-09-17 09:57    [W:0.257 / U:0.120 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site