[Bug libdw/21174] New: libdw with perf: duplication of entries in callstack

[Bug libdw/21174] New: libdw with perf: duplication of entries in callstack

[thommyj at gmail dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

            Bug ID: 21174
           Summary: libdw with perf: duplication of entries in callstack
           Product: elfutils
           Version: unspecified
            Status: UNCONFIRMED
          Severity: normal
          Priority: P2
         Component: libdw
          Assignee: unassigned at sourceware dot org
          Reporter: thommyj at gmail dot com
                CC: elfutils-devel at sourceware dot org
  Target Milestone: ---

Hi,

running perf together with libdw for stack unwinding using dwarf on an
arm64 board. I'm a bit puzzled of the callstack that is unwinded.
Sometimes I get the same entry twice out from libdw

Normal sample:
23_HalInterrupt   462  1087.469883:    6802721 cpu-clock:
         6e3628 IBUFDIST_distribute (/usr/local/bin/Application)
         6f33bc endOfFrame (/usr/local/bin/Application)
         6f2fcc interrupt (/usr/local/bin/Application)
         6f8c9c interruptHandler (/usr/local/bin/Application)
         6f7130 taskFunction (/usr/local/bin/Application)
     7fae555df8 [unknown] (/lib/libpthread-2.19-2014.08.so)

Sample with duplicated entries
23_HalInterrupt   462  1028.701041:    6802721 cpu-clock:
         6e3628 IBUFDIST_distribute (/usr/local/bin/Application)
         6e3628 IBUFDIST_distribute (/usr/local/bin/Application)
         6f33bc endOfFrame (/usr/local/bin/Application)
         6f2fcc interrupt (/usr/local/bin/Application)
         6f8c9c interruptHandler (/usr/local/bin/Application)
         6f7130 taskFunction (/usr/local/bin/Application)
     7fae555df8 [unknown] (/lib/libpthread-2.19-2014.08.so)

Sometimes it is the same address for the duplicate entry, sometimes
its different addresses but same symbol name. Its not always the first
entry, but seems to be more likely on first.

Is this a known problem?

BR,
Thommy Jakobsson

#record
>>perf record -t 462 -F 147 -g --call-graph dwarf -o halinter2.perf sleep 30
#dump data
>>perf script -i halinter2.perf

linux 4.4
elfutils 0.163
aarch64-linux-gnu-gcc (crosstool-NG linaro-1.13.1-4.9-2014.09 - Linaro
GCC 4.9-2014.09) 4.9.2 20140904 (prerelease)
Copyright (C) 2014 Free Software Found

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[mark at klomp dot org]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

Mark Wielaard <mark at klomp dot org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |mark at klomp dot org

--- Comment #1 from Mark Wielaard <mark at klomp dot org> ---
There is no good way to tell. It could happen if the function calls itself
(although you would expect the pc to be different). How does perf call the
libdw getframe function? What does the CFI look like at that address?

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[thommyj at gmail dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #2 from Thommy Jakobsson <thommyj at gmail dot com> ---
Created attachment 9833
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9833&action=edit
disassembly of function IBUFDIST_distribute

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[thommyj at gmail dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #3 from Thommy Jakobsson <thommyj at gmail dot com> ---
(In reply to Mark Wielaard from comment #1)
> There is no good way to tell. It could happen if the function calls itself
> (although you would expect the pc to be different).

I did check the assembler code for one case, and couldn't find anything
special, no calling of itself (although I didn't really know what to search for
either so I might have missed something =) ). Checking the code for the
specific example I pasted here it seems to be a return address for another
call. See attached file.

> How does perf call the libdw getframe function?
The actual call looks like this
err = dwfl_getthread_frames(ui.dwfl, thread->tid, frame_callback, &ui);
but I assume that you want some specific information? The entire wrapper around
libdw can be found here
http://lxr.free-electrons.com/source/tools/perf/util/unwind-libdw.c?v=4.4

> What does the CFI look like at that address?
How can I find this out? dwarfdump?

BR,
Thommy Jakobsson

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[mark at klomp dot org]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #4 from Mark Wielaard <mark at klomp dot org> ---
(In reply to Thommy Jakobsson from comment #2)
> Created attachment 9833 [details]
> disassembly of function IBUFDIST_distribute

That shows the (duplicated) address 6e3628 is the last one before the return of
the function:

  6e3628:       a8c27bfd        ldp     x29, x30, [sp],#32
  6e362c:       d65f03c0        ret

Maybe something gets confused by the stack adjustment?

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[mark at klomp dot org]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #5 from Mark Wielaard <mark at klomp dot org> ---
(In reply to Thommy Jakobsson from comment #3)
> (In reply to Mark Wielaard from comment #1)
> > How does perf call the libdw getframe function?
> The actual call looks like this
> err = dwfl_getthread_frames(ui.dwfl, thread->tid, frame_callback, &ui);
> but I assume that you want some specific information? The entire wrapper
> around libdw can be found here
> http://lxr.free-electrons.com/source/tools/perf/util/unwind-libdw.c?v=4.4

Maybe you can debug by triggering the pr_debug () to show what libdwfl returned
and compare it with how perf then prints out the struct ui that should hold the
same addresses to know which part of the code the duplicated address comes
from.

> > What does the CFI look like at that address?
> How can I find this out? dwarfdump?

eu-readelf --debug-dump=frame /usr/local/bin/Application
and look for the program covering initial_location and address range that
covers the address.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[thommyj at gmail dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #6 from Thommy Jakobsson <thommyj at gmail dot com> ---
Hi again and thanks for spending the time.

>>Maybe you can debug by triggering the pr_debug ()
Switched the pr_debug to a normal printf, and also added a printout of program
counter directly in the libdw frame callback (see attached patch). And from
what I can see the duplication of symbol comes from libdw

>>eu-readelf --debug-dump=frame /usr/local/bin/Application
Not fully understand how to read the callstack debug data, is this what you
want? I guess you are supposed to unroll the entire register file from last
function with this info, so I would have expected more data.

 [  1ad8] FDE length=36 cie=[  1aa0]
   CIE_pointer:              6816
   initial_location:         0x00000000006e35d8 <IBUFDIST_distribute>
   address_range:            0x58

   Program:
     advance_loc 2 to 0x4
     def_cfa_offset 32
     offset r29 (x29) at cfa-32
     offset r30 (x30) at cfa-24
     advance_loc 2 to 0x8
     def_cfa_register r29 (x29)
     advance_loc 38 to 0x54
     restore r30 (x30)
     restore r29 (x29)
     def_cfa r31 (sp) at offset 0

 [  1b00] CIE length=12
   CIE_id:                   18446744073709551615
   version:                  1
   augmentation:             ""
   code_alignment_factor:    2
   data_alignment_factor:    -4
   return_address_register:  30

   Program:
     def_cfa r31 (sp) at offset 0

BR,
Thommy Jakobsson

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug libdw/21174] libdw with perf: duplication of entries in callstack

[thommyj at gmail dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=21174

--- Comment #7 from Thommy Jakobsson <thommyj at gmail dot com> ---
Created attachment 9834
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9834&action=edit
Add debug printouts in the perf stack unwind

-- 
You are receiving this mail because:
You are on the CC list for the bug.