Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1470096

[BUG] perf tool: uprobe displays wrong argument value

Path csiph.com!news.mixmin.net!news.unit0.net!news.panservice.it!bofh.it!news.nic.it!robomod
From Jiri Olsa <jolsa@redhat.com>
Newsgroups linux.kernel
Subject [BUG] perf tool: uprobe displays wrong argument value
Date Thu, 25 Aug 2016 14:10:01 +0200
Message-ID <sa1DP-Mw-13@gated-at.bofh.it> (permalink)
MIME-Version 1.0
Content-Type text/plain; charset=us-ascii
Content-Disposition inline
User-Agent Mutt/1.7.0 (2016-08-17)
X-Scanned-By MIMEDefang 2.68 on 10.5.11.24
X-Greylist Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.38]); Thu, 25 Aug 2016 12:02:53 +0000 (UTC)
Sender robomod@news.nic.it
List-ID <linux-kernel.vger.kernel.org>
X-Mailing-List linux-kernel@vger.kernel.org
Approved robomod@news.nic.it
Lines 112
Organization linux.* mail to news gateway
X-Original-Cc Arnaldo Carvalho de Melo <acme@kernel.org>, linux-kernel@vger.kernel.org, Peter Zijlstra <peterz@infradead.org>, Ingo Molnar <mingo@redhat.com>, Michael Petlan <mpetlan@redhat.com>, Namhyung Kim <namhyung@kernel.org>, pbunyan@redhat.com
X-Original-Date Thu, 25 Aug 2016 14:02:50 +0200
X-Original-Message-ID <20160825120250.GB8319@krava>
X-Original-Sender linux-kernel-owner@vger.kernel.org
Xref csiph.com linux.kernel:1470096

Show key headers only | View raw


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

Back to linux.kernel | Previous | NextNext in thread | Find similar | Unroll thread


Thread

[BUG] perf tool: uprobe displays wrong argument value Jiri Olsa <jolsa@redhat.com> - 2016-08-25 14:10 +0200
  Re: [BUG] perf tool: uprobe displays wrong argument value Yauheni Kaliuta <yauheni.kaliuta@redhat.com> - 2016-08-25 15:20 +0200
    Re: [BUG] perf tool: uprobe displays wrong argument value Namhyung Kim <namhyung@kernel.org> - 2016-08-26 05:50 +0200

csiph-web