"perf script" broken with --call-graph=dwarf on recent kernels?

DISCUSSION Ben Redelings 4 participants 7 messages Aug 17, 2015 – Nov 2, 2015

Share & tools

Ben Redelings

author

2015-08-17 16:25 UTC #0 lore raw

Hi,

The behavior of "perf script" has changed on recent kernels, and
I'm wondering whether this is a bug, or whether I'm just missing something. (I'm perf script to generate DOT graphs for user-space profiling via the gprof2dot script: https://github.com/jrfonseca/gprof2dot)

If I run perf record with --call-graph=dwarf, then I can run perf
report and view call-chains. However, if I run 'perf script' I don't see any call chains, but just output like:

bali-phy 11043 10381.662885: 466982 cycles:

bali-phy 11043 10381.663136: 466737 cycles:

bali-phy 11043 10381.663386: 466456 cycles:

bali-phy 11043 10381.663636: 466465 cycles:

bali-phy 11043 10381.663885: 466611 cycles:

bali-phy 11043 10381.664135: 466757 cycles:

with an occasional

bali-phy 11043 10381.665885: 466867 cycles:
ffffffff81577e30 page_fault ([kernel.kallsyms])

If I run with --call-graph=lbr instead, then I get 'perf script'
output like this instead:

bali-phy 11060 10464.369184: 420718 cycles:
3437d0 all_characters_connected
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
3448c8 check_internal_nodes_connected
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
3450fc check_alignment
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)

bali-phy 11060 10464.369412: 427217 cycles:
26ef10 alignment::alignment
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
305f7e empirical_frequencies
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
306ce1 empirical_frequencies
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)

                  3330d9 get_smodel 
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                  4dc133 get_smodels 
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                  4e02ea create_A_and_T_model

(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)

This is more what I was expecting, and similar to what I used to get with --call-graph=dwarf.

However, the call chains that I get using DWARF tend to be longer and lead to more accurate results, so I would prefer to use DWARF instead of lbr. Is there something that I'm doing wrong? Also, it seems like --call-graph=dwarf successfully records call chains that can be seen via perf report, but somehow 'perf script' doesn't show them. Could that happen?

-BenRI

P.S. I'm using debian's kernel 4.1.0 and perf tools on a Core i3-4030.

Jiri Olsa

2015-08-18 07:05 UTC #1 lore raw

On Mon, Aug 17, 2015 at 12:25:29PM -0400, Ben Redelings wrote:

SNIP

Quoted 20 lines

(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
306ce1 empirical_frequencies
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                  3330d9 get_smodel
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                  4dc133 get_smodels
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                  4e02ea create_A_and_T_model
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
This is more what I was expecting, and similar to what I used to get with --call-graph=dwarf.
However, the call chains that I get using DWARF tend to be longer and lead to more accurate results, so I would prefer to use DWARF instead of lbr. Is there something that I'm doing wrong? Also, it seems like --call-graph=dwarf successfully records call chains that can be seen via perf report, but somehow 'perf script' doesn't show them. Could that happen?

Quoted 3 lines

-BenRI
P.S. I'm using debian's kernel 4.1.0 and perf tools on a Core i3-4030.

hum, it's probably fixed already:
http://marc.info/?l=linux-kernel&m=143945026316969&w=2

it's currently in Arnaldo's perf/core branch

jirka

Ben Redelings

author

2015-08-18 18:28 UTC #2 lore raw

Yeah, I applied the patch you posted, and it works. Thanks!

-BenRI

Quoted 33 lines · Jiri Olsa

On Mon, Aug 17, 2015 at 12:25:29PM -0400, Ben Redelings wrote:
SNIP
Quoted 20 lines
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
306ce1 empirical_frequencies
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                   3330d9 get_smodel
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                   4dc133 get_smodels
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
                   4e02ea create_A_and_T_model
(/home/bredelings/Devel/bali-phy/local/clang-3.7/bin/bali-phy)
This is more what I was expecting, and similar to what I used to get with --call-graph=dwarf.
However, the call chains that I get using DWARF tend to be longer and lead to more accurate results, so I would prefer to use DWARF instead of lbr. Is there something that I'm doing wrong? Also, it seems like --call-graph=dwarf successfully records call chains that can be seen via perf report, but somehow 'perf script' doesn't show them. Could that happen?
Quoted 3 lines
-BenRI
P.S. I'm using debian's kernel 4.1.0 and perf tools on a Core i3-4030.
hum, it's probably fixed already:
http://marc.info/?l=linux-kernel&m=143945026316969&w=2
it's currently in Arnaldo's perf/core branch
jirka

Ben Redelings

author

2015-10-31 13:25 UTC #3 lore raw

Inverted call-graph broken?

In reply to Ben Redelings

Hi,

I've been using perf with '--call-graph=dwarf' -- very useful! I'd
like to view call graphs in 'perf report' in "inverted" order. Adding '-G' to 'perf report' appears to have no effect, though. (Also '--call-graph=fractal,caller' has no effect.) Am I missing something obvious?

-BenRI

Milian Wolff

2015-11-01 14:09 UTC #4 lore raw

Re: Inverted call-graph broken?

Quoted 7 lines · On Samstag, 31. Oktober 2015 09:25:39 CET Ben Redelings wrote:

Hi,
I've been using perf with '--call-graph=dwarf' -- very useful! I'd
like to view call graphs in 'perf report' in "inverted" order. Adding '-G' to 'perf report' appears to have no effect, though. (Also '--call-graph=fractal,caller' has no effect.) Am I missing something obvious?

This was broken and only recently got fixed by me and Jiri.

http://article.gmane.org/gmane.linux.kernel.perf.user/2279

Afaik, the patch has not yet been included upstream though. Arnaldo, can you take Jiri's patch, or is there still something left to be done?

Cheers

Signature · 4 lines

Milian Wolff | [email protected] | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

Arnaldo Carvalho de Melo

2015-11-02 17:31 UTC #5 lore raw

Re: Inverted call-graph broken?

Em Sun, Nov 01, 2015 at 03:09:45PM +0100, Milian Wolff escreveu:

Quoted 7 lines · On Samstag, 31. Oktober 2015 09:25:39 CET Ben Redelings wrote:

Quoted 5 lines
I've been using perf with '--call-graph=dwarf' -- very useful! I'd
like to view call graphs in 'perf report' in "inverted" order. Adding '-G' to 'perf report' appears to have no effect, though. (Also '--call-graph=fractal,caller' has no effect.) Am I missing something obvious?

Quoted 6 lines

This was broken and only recently got fixed by me and Jiri.
http://article.gmane.org/gmane.linux.kernel.perf.user/2279
Afaik, the patch has not yet been included upstream though. Arnaldo, can you take Jiri's patch, or is there still something left to be done?

I'll check, but please post the title of the message, the gmane link above isn't working for me, produces:

"Gmane weft didn't produce an output."

A Message-Id would be even better.

- Arnaldo

Milian Wolff

2015-11-02 18:29 UTC #6 lore raw

Re: Inverted call-graph broken?

Quoted 16 lines · CET Arnaldo Carvalho de Melo

Em Sun, Nov 01, 2015 at 03:09:45PM +0100, Milian Wolff escreveu:
Quoted 8 lines · On Samstag, 31. Oktober 2015 09:25:39 CET Ben Redelings wrote:
Quoted 6 lines
I've been using perf with '--call-graph=dwarf' -- very useful! I'd
like to view call graphs in 'perf report' in "inverted" order. Adding '-G' to 'perf report' appears to have no effect, though. (Also '--call-graph=fractal,caller' has no effect.) Am I missing something obvious?
Quoted 6 lines
This was broken and only recently got fixed by me and Jiri.
http://article.gmane.org/gmane.linux.kernel.perf.user/2279
Afaik, the patch has not yet been included upstream though. Arnaldo, can you take Jiri's patch, or is there still something left to be done?

Quoted 6 lines

I'll check, but please post the title of the message, the gmane link above isn't working for me, produces:
"Gmane weft didn't produce an output."
A Message-Id would be even better.

Subject: [PATCH] perf report: Support caller callchain order when using DWARF unwinder.

Message-Id: <[email protected]>

Cheers

Signature · 4 lines

Milian Wolff | [email protected] | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts