Re: perf is unable to read dward from go programs

From: Jiri Olsa
Date: Fri Nov 29 2019 - 08:49:45 EST


On Wed, Nov 27, 2019 at 01:15:20PM -0800, Ivan Babrou wrote:
> There were no response in linux-perf-users@, so I think it's fair to
> ask maintainers.
>
> On Fri, Nov 8, 2019 at 3:53 PM Ivan Babrou <ivan@xxxxxxxxxxxxxx> wrote:
> >
> > I have a simple piece of code that burns CPU for 1s:
> >
> > * https://gist.github.com/bobrik/cf022ff6950d09032fa13a984e2272ed
> >
> > I can build it just fine: go build -o /tmp/burn burn.go
> >
> > And I can see correct stacks if I record with fp:
> >
> > perf record -e cpu-clock -g -F 99 /tmp/burn
> >
> > But if I record with gwarf:
> >
> > perf record -e cpu-clock -g -F 99 --call-graph dwarf /tmp/burn
> >
> > Then stacks are lost with the following complaints during "perf script":
> >
> > BFD: Dwarf Error: found dwarf version '376', this reader only handles
> > version 2, 3 and 4 information.
> > BFD: Dwarf Error: found dwarf version '31863', this reader only
> > handles version 2, 3 and 4 information.
> > BFD: Dwarf Error: found dwarf version '65271', this reader only
> > handles version 2, 3 and 4 information.
> > BFD: Dwarf Error: found dwarf version '289', this reader only handles
> > version 2, 3 and 4 information.

hi,
the binary generated by go has compressed debug info (on my setup)
and libunwind (default dwarf unwinder) does not seem to support that

but when I compile perf with libdw unwind support:

$ make DEBUG=1 VF=1 NO_LIBUNWIND=1

I'm getting proper backtraces (below), maybe it's time to change
the default dwarf unwinder ;-)

thanks,
jirka


---
51.63% ex ex [.] crypto/sha512.blockAVX2
|
---crypto/sha512.blockAVX2
|
--51.48%--crypto/sha512.block
crypto/sha512.(*digest).Write
crypto/sha512.(*digest).checkSum
crypto/sha512.(*digest).Sum
main.burn
main.main
runtime.main
runtime.goexit

11.55% ex ex [.] runtime.mallocgc
|
---runtime.mallocgc
|
|--7.45%--runtime.newobject
| |
| --7.45%--main.burn
| main.main
| runtime.main
| runtime.goexit
|
--3.40%--runtime.growslice
crypto/sha512.(*digest).Sum
main.burn
main.main
runtime.main
runtime.goexit

3.69% ex ex [.] crypto/sha512.(*digest).Write
|
---crypto/sha512.(*digest).Write
|
|--2.91%--crypto/sha512.(*digest).checkSum
| crypto/sha512.(*digest).Sum
| main.burn
| main.main
| runtime.main
| runtime.goexit
|
--0.57%--main.burn
main.main
runtime.main
runtime.goexit

3.44% ex ex [.] runtime.memclrNoHeapPointers
|
---runtime.memclrNoHeapPointers
|
--2.92%--runtime.(*mheap).alloc
runtime.(*mcentral).grow
runtime.(*mcentral).cacheSpan
runtime.(*mcache).refill
runtime.(*mcache).nextFree
runtime.mallocgc
|
|--2.27%--runtime.newobject
| main.burn
| main.main
| runtime.main
| runtime.goexit
|
--0.64%--runtime.growslice
crypto/sha512.(*digest).Sum
main.burn
main.main
runtime.main
runtime.goexit
...