[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20160825120250.GB8319@krava>
Date: Thu, 25 Aug 2016 14:02:50 +0200
From: Jiri Olsa <jolsa@...hat.com>
To: Masami Hiramatsu <mhiramat@...nel.org>
Cc: Arnaldo Carvalho de Melo <acme@...nel.org>,
linux-kernel@...r.kernel.org,
Peter Zijlstra <peterz@...radead.org>,
Ingo Molnar <mingo@...hat.com>,
Michael Petlan <mpetlan@...hat.com>,
Namhyung Kim <namhyung@...nel.org>, pbunyan@...hat.com
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
Powered by blists - more mailing lists