perf/core improvements and fixes

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 3 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Quoted 1 line

Which is the most common default found in other similar tools.

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

# perf report -n --stdio
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- 0x7f0683ba1ccd
                         system_call_fastpath
                         sys_write
                         vfs_write
                         do_sync_write
                         sock_aio_write
                         do_sock_write.isra.10
                         inet_sendmsg
                         copy_user_enhanced_fast_string
[...]

That's upside down. The current default preserves ordering from the informational line onwards:

# perf report -n --stdio -g fractal,0.5,callee
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- copy_user_enhanced_fast_string
                        |
                        |--64.37%-- inet_sendmsg
                        |          do_sock_write.isra.10
                        |          sock_aio_write
                        |          do_sync_write
                        |          vfs_write
                        |          sys_write
                        |          system_call_fastpath
                        |          0x7f0683ba1ccd

... Those are just short examples. Another profile I'm working on now gets really messy on "perf report -n --stdio"; eg:

perf report -n --stdio -g graph,0.5,caller

    94.80%     0.10%             2  iperf     [kernel.vmlinux]    [k]
entry_SYSCALL_64_fastpath
               |
               |--94.70%-- entry_SYSCALL_64_fastpath
               |          |

The current default never gets beyond 5 levels deep. The new default goes to 25 levels. At least with perf report I can override the default using "-g". perf script doesn't support that.

Can this patch please preserve the callee ordering for non-interactive output? (perf script, perf report -n --stdio). Thanks,

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Quoted 45 lines

# perf report -n --stdio
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- 0x7f0683ba1ccd
                         system_call_fastpath
                         sys_write
                         vfs_write
                         do_sync_write
                         sock_aio_write
                         do_sock_write.isra.10
                         inet_sendmsg
                         copy_user_enhanced_fast_string
[...]

That's upside down. The current default preserves ordering from the informational line onwards:

# perf report -n --stdio -g fractal,0.5,callee
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- copy_user_enhanced_fast_string
                        |
                        |--64.37%-- inet_sendmsg
                        |          do_sock_write.isra.10
                        |          sock_aio_write
                        |          do_sync_write
                        |          vfs_write
                        |          sys_write
                        |          system_call_fastpath
                        |          0x7f0683ba1ccd

... Those are just short examples. Another profile I'm working on now gets really messy on "perf report -n --stdio"; eg:

perf report -n --stdio -g graph,0.5,caller

    94.80%     0.10%             2  iperf     [kernel.vmlinux]    [k]
entry_SYSCALL_64_fastpath
               |
               |--94.70%-- entry_SYSCALL_64_fastpath
               |          |

Quoted 3 lines

The current default never gets beyond 5 levels deep. The new default goes to 25 levels. At least with perf report I can override the default using "-g". perf script doesn't support that.

Ok, so changing defaults is not nice, but in this case looked sensible, ends up not being for you...

Quoted 3 lines

Can this patch please preserve the callee ordering for non-interactive output? (perf script, perf report -n --stdio). Thanks,

If this is because you do scripting on it? Wouldn't it be better to not depend on defaults, always specify what you want and then the bug would be constrained to 'perf script' where we need to provide a way to change the default?

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

But it's not just scripting; We often email around "perf report -n --stdio" output, or attach it to tickets, when working on an issue. Easier than trying to grab the right TUI screenshot.

Quoted 45 lines

Quoted 45 lines

# perf report -n --stdio
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- 0x7f0683ba1ccd
                         system_call_fastpath
                         sys_write
                         vfs_write
                         do_sync_write
                         sock_aio_write
                         do_sock_write.isra.10
                         inet_sendmsg
                         copy_user_enhanced_fast_string
[...]

That's upside down. The current default preserves ordering from the informational line onwards:

# perf report -n --stdio -g fractal,0.5,callee
[...]
    16.87%        334           iperf  [kernel.kallsyms]     [k] copy_user_enhanced_fast_string
                     |
                     --- copy_user_enhanced_fast_string
                        |
                        |--64.37%-- inet_sendmsg
                        |          do_sock_write.isra.10
                        |          sock_aio_write
                        |          do_sync_write
                        |          vfs_write
                        |          sys_write
                        |          system_call_fastpath
                        |          0x7f0683ba1ccd

... Those are just short examples. Another profile I'm working on now gets really messy on "perf report -n --stdio"; eg:

perf report -n --stdio -g graph,0.5,caller

    94.80%     0.10%             2  iperf     [kernel.vmlinux]    [k]
entry_SYSCALL_64_fastpath
               |
               |--94.70%-- entry_SYSCALL_64_fastpath
               |          |

Quoted 6 lines

Quoted 3 lines

The current default never gets beyond 5 levels deep. The new default goes to 25 levels. At least with perf report I can override the default using "-g". perf script doesn't support that.

Ok, so changing defaults is not nice, but in this case looked sensible, ends up not being for you...

I'm pretty sure this would surprise anyone looking at dumped stacks, where the convention is caller. pstack, jstack, gdb, systemtap, dtrace, oops message, etc. I get that we want this for the TUI, but not dumped stacks.

Quoted 3 lines

Quoted 2 lines

Can this patch please preserve the callee ordering for non-interactive output? (perf script, perf report -n --stdio). Thanks,

Quoted 4 lines

If this is because you do scripting on it? Wouldn't it be better to not depend on defaults, always specify what you want and then the bug would be constrained to 'perf script' where we need to provide a way to change the default?

Actually, for my flame graphs we should really have perf report have a --folded output to emit folded output (I emailed perf-users), callee.

For scripting we can always specify -g.

I'm thinking of others who use perf report/script at the CLI, and expect callee output.

Em Fri, Oct 09, 2015 at 03:10:29PM -0700, Brendan Gregg escreveu:

Quoted 19 lines

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Quoted 8 lines

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

Should've already, guess there are things to merge and save you some time :)

Quoted 3 lines

But it's not just scripting; We often email around "perf report -n --stdio" output, or attach it to tickets, when working on an issue. Easier than trying to grab the right TUI screenshot.

Well, that is something we need to change... But then, are you aware of 'P' in the TUI? It allows you to go, expand whatever callchains you deem necessary and then press P and the current state of the UI will be dumped to a perf.hist.<N> file. I.e. no need to get a png screenshot nor to copy things with gpm like stuff.
[...]

Quoted 34 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 03:10:29PM -0700, Brendan Gregg escreveu:

Quoted 17 lines

Quoted 7 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 5 lines

Quoted 3 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Quoted 8 lines

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

Should've already, guess there are things to merge and save you some time :)

Quoted 3 lines

But it's not just scripting; We often email around "perf report -n --stdio" output, or attach it to tickets, when working on an issue. Easier than trying to grab the right TUI screenshot.

Quoted 6 lines

Well, that is something we need to change... But then, are you aware of 'P' in the TUI? It allows you to go, expand whatever callchains you deem necessary and then press P and the current state of the UI will be dumped to a perf.hist.<N> file. I.e. no need to get a png screenshot nor to copy things with gpm like stuff.
[...]

I didn't know about 'P', thanks. I still find it quicker to "perf report -n --stdio", then browse with my eyes and the scroll wheel. (Then use a flame graph if the output isn't trivial to understand.)

... Just to express a callee order preference differently (at least for the text dumping outputs), it's showing what's running (first few frames) followed by how we got there. And that's the order I'm usually wanting to know them... I still think it's the order printed by most other text-based tools, although GUIs (like those with tree views) are probably more usually caller order.

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

This is all configurable via ~/.perfconfig :-\

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Ingo, what do you think?

- Arnaldo

Quoted 3 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

Quoted 4 lines

This is all configurable via ~/.perfconfig :-\

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

IMHO changing that order is not a good idea. Unless many users complained about it.

Quoted 1 line

Ingo, what do you think?

Em Tue, Oct 20, 2015 at 02:19:50PM +0200, Frederic Weisbecker escreveu:

Quoted 6 lines · Arnaldo Carvalho de Melo

Quoted 5 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

This is all configurable via ~/.perfconfig :-\

Quoted 5 lines

Quoted 2 lines

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

A good chunk of that was because that was the default?

Quoted 3 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

Anedoctally, he tweeted about it and people seemed to like it.

Quoted 1 line

Quoted 1 line

Ingo, what do you think?

What about providing a hotkey, in the tui, to toggle caller/callee views, and another hotkey to save that in ~/.perfconfig so that becomes the new default?

In the --stdio mode we need to add a warning in the first lines, something like:

# This is caller (or callee) based, please use --callchain ... to change it

One way or the other people will disagree, so making it easy to switch to the preferred way would be nice to have?

Quoted 11 lines

Em Tue, Oct 20, 2015 at 02:19:50PM +0200, Frederic Weisbecker escreveu:

Quoted 9 lines · Arnaldo Carvalho de Melo

Quoted 8 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

This is all configurable via ~/.perfconfig :-\

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Quoted 4 lines

Quoted 2 lines

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

A good chunk of that was because that was the default?

I doubt it. When you need to find the culprit of a syscall of IRQ performance issue, you don't care much to see __libc_start_main() / main() on the top of your callchain.

Quoted 6 lines

Quoted 2 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Quoted 4 lines

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

Anedoctally, he tweeted about it and people seemed to like it.

Well, I would prefer to hear from regular users than random twitter followers. I could be wrong so lets ask some users first.

Quoted 5 lines

Quoted 1 line

Quoted 1 line

Ingo, what do you think?

What about providing a hotkey, in the tui, to toggle caller/callee views, and another hotkey to save that in ~/.perfconfig so that becomes the new default?

That means rebuilding the whole tree, it might be costly and events need to be processed again.

Quoted 7 lines

In the --stdio mode we need to add a warning in the first lines, something like:

# This is caller (or callee) based, please use --callchain ... to change it

One way or the other people will disagree, so making it easy to switch to the preferred way would be nice to have?

Agreed.

Em Tue, Oct 20, 2015 at 07:21:16PM +0200, Frederic Weisbecker escreveu:

Quoted 15 lines · Arnaldo Carvalho de Melo

Quoted 14 lines

Em Tue, Oct 20, 2015 at 02:19:50PM +0200, Frederic Weisbecker escreveu:

Quoted 12 lines · Arnaldo Carvalho de Melo

Quoted 8 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

This is all configurable via ~/.perfconfig :-\

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

Quoted 4 lines

Quoted 1 line

A good chunk of that was because that was the default?

I doubt it. When you need to find the culprit of a syscall of IRQ performance issue, you don't care much to see __libc_start_main() / main() on the top of your callchain.

And I noticed some other shortcoming of this ordering (caller) the stack closer to userspace in a typical perf.data with callchains (perf record -g) can have bogus addresses (-fomit-frame-pointer) :-\

Quoted 7 lines

Quoted 7 lines

Quoted 3 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Quoted 7 lines

Quoted 4 lines

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

Anedoctally, he tweeted about it and people seemed to like it.

Well, I would prefer to hear from regular users than random twitter followers. I could be wrong so lets ask some users first.

That is why I put the "anedoctaly" :-)

Quoted 5 lines

Quoted 5 lines

Quoted 1 line

Quoted 1 line

Ingo, what do you think?

What about providing a hotkey, in the tui, to toggle caller/callee views, and another hotkey to save that in ~/.perfconfig so that becomes the new default?

Quoted 2 lines

That means rebuilding the whole tree, it might be costly and events need to be processed again.

I never tried to reimplement that with going to/from caller/caller in mind, should do at some point, but yeah, reprocessing all entries can be way costly.

Quoted 6 lines

Quoted 6 lines

In the --stdio mode we need to add a warning in the first lines, something like:

# This is caller (or callee) based, please use --callchain ... to change it

Quoted 4 lines

Quoted 2 lines

One way or the other people will disagree, so making it easy to switch to the preferred way would be nice to have?

Agreed.

I'll probably revert this change in default and provide some way to change it dynamically, just waiting a some more time for more comments.

Quoted 5 lines

Em Tue, Oct 20, 2015 at 07:21:16PM +0200, Frederic Weisbecker escreveu:

Quoted 1 line · Arnaldo Carvalho de Melo

And I noticed some other shortcoming of this ordering (caller) the stack closer to userspace in a typical perf.data with callchains (perf record -g) can have bogus addresses (-fomit-frame-pointer) :-\

Maybe we need to add an option to ignore unresolved callchains?

Quoted 8 lines · Arnaldo Carvalho de Melo

Em Tue, Oct 20, 2015 at 02:19:50PM +0200, Frederic Weisbecker escreveu:

Quoted 6 lines · Arnaldo Carvalho de Melo

Quoted 5 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?

This is all configurable via ~/.perfconfig :-\

Quoted 7 lines

Quoted 5 lines

Quoted 2 lines

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

A good chunk of that was because that was the default?

I doubt it. When you need to find the culprit of a syscall of IRQ performance issue, you don't care much to see __libc_start_main() / main() on the top of your callchain.

Quoted 7 lines

Quoted 3 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Quoted 4 lines

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

Anedoctally, he tweeted about it and people seemed to like it.

Well, I would prefer to hear from regular users than random twitter followers. I could be wrong so lets ask some users first.

Hi Frederic,

Quoted 22 lines · Frederic Weisbecker

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Tue, Oct 20, 2015 at 02:19:50PM +0200, Frederic Weisbecker escreveu:

Quoted 7 lines · Arnaldo Carvalho de Melo

Quoted 6 lines

Em Mon, Oct 19, 2015 at 05:16:53PM -0700, Brendan Gregg escreveu:
So are you advocating different defaults, one for --stdio (callee), another for --tui, --gtk (caller)?
This is all configurable via ~/.perfconfig :-\
Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Quoted 3 lines

Quoted 2 lines

Most uses I've seen on LKML by the past involved callee because people mostly look at the precise point where a performance issue is.

A good chunk of that was because that was the default?

I doubt it. When you need to find the culprit of a syscall of IRQ performance issue, you don't care much to see __libc_start_main() / main() on the top of your callchain.

Quoted 6 lines

Quoted 3 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Quoted 6 lines

Quoted 4 lines

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

Anedoctally, he tweeted about it and people seemed to like it.

Well, I would prefer to hear from regular users than random twitter followers. I could be wrong so lets ask some users first.

Just a question. Do you often use --children and/or '--g caller' options?

I guess that for most kernel developers, --children is not that useful as you said. But I think it can be useful for many userspace developers and with '-g caller' it can be even more useful. :)

When '-g caller' is used, the callchains shown in a (self) entry are less important IMHO. However callchains in entries generated by --children will show which functions are called by the entry (since it's reversed!) and will be more important.

Thanks,
Namhyung

Quoted 2 lines · Frederic Weisbecker

Well, I would prefer to hear from regular users than random twitter followers. I could be wrong so lets ask some users first.

Just a question. Do you often use --children and/or '--g caller' options?

I guess that for most kernel developers, --children is not that useful as you said.

But I think it can be useful for many userspace developers and with '-g caller' it can be even more useful. :)

When '-g caller' is used, the callchains shown in a (self) entry are less important IMHO. However callchains in entries generated by --children will show which functions are called by the entry (since it's reversed!) and will be more important.

Quoted 9 lines · Arnaldo Carvalho de Melo

Quoted 2 lines

IMHO changing that order is not a good idea. Unless many users complained about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

So, first and foremost, thanks for fixing some of my gripes about the usability of the perf tool, I'm super excited about the changes you're making, even if this one isn't among them.

I think the default of caller vs. callee is probably the hardest judgement call to make about the right defaults. I can see it going both ways.

When profiling my *system*, or a diverse group of programs or tasks, I often find callee useful. Were I a kernel developer, I suspect callee would be *dramatically* more common than caller.

For me, what makes the caller view much more frequently desired is that I'm usually profiling a fairly isolated application, or benchmark for an isolated library. While I always start off with some more system-level performance problem, I rarely need a detailed profile to get a reasonable idea of what subsystem to stare at, and then I spend days looking at a relatively isolated reproduction.

Anyways, for profiling user-land applications, I suspect from my conversations with users that "caller" is the more common expectation.

Quoted 4 lines

What about providing a hotkey, in the tui, to toggle caller/callee views, and another hotkey to save that in ~/.perfconfig so that becomes the new default?

OMG, being able to toggle between caller and callee in the tui would be *awesome*. Regardless of which default you end up with, I'd love to have this feature.

Since Arnaldo asked, I thought I should actually try to respond specifically to the question of why I favor the 'caller' view as the default.

Quoted 10 lines · Arnaldo Carvalho de Melo

Quoted 4 lines

IMHO changing that order is not a good idea. Unless many users complained
about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

So, first and foremost, thanks for fixing some of my gripes about the usability of the perf tool, I'm super excited about the changes you're making, even if this one isn't among them.

I think the default of caller vs. callee is probably the hardest judgement call to make about the right defaults. I can see it going both ways.

When profiling my *system*, or a diverse group of programs or tasks, I often find callee useful. Were I a kernel developer, I suspect callee would be *dramatically* more common than caller.

For me, what makes the caller view much more frequently desired is that I'm usually profiling a fairly isolated application, or benchmark for an isolated library. While I always start off with some more system-level performance problem, I rarely need a detailed profile to get a reasonable idea of what subsystem to stare at, and then I spend days looking at a relatively isolated reproduction.

Anyways, for profiling user-land applications, I suspect from my conversations with users that "caller" is the more common expectation.

Quoted 35 lines

Since Arnaldo asked, I thought I should actually try to respond specifically to the question of why I favor the 'caller' view as the default.

Quoted 10 lines · Arnaldo Carvalho de Melo

Quoted 4 lines

IMHO changing that order is not a good idea. Unless many users complained
about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

So, first and foremost, thanks for fixing some of my gripes about the usability of the perf tool, I'm super excited about the changes you're making, even if this one isn't among them.

I think the default of caller vs. callee is probably the hardest judgement call to make about the right defaults. I can see it going both ways.

When profiling my *system*, or a diverse group of programs or tasks, I often find callee useful. Were I a kernel developer, I suspect callee would be *dramatically* more common than caller.

For me, what makes the caller view much more frequently desired is that I'm usually profiling a fairly isolated application, or benchmark for an isolated library. While I always start off with some more system-level performance problem, I rarely need a detailed profile to get a reasonable idea of what subsystem to stare at, and then I spend days looking at a relatively isolated reproduction.

Quoted 2 lines

Anyways, for profiling user-land applications, I suspect from my conversations with users that "caller" is the more common expectation.

[...]

I would have said callee is the more common expectation, certainly for system profilers. I quickly checked various tools to see what their defaults are:

callee:

gdb
lldb
pstack
jstack
perf
stap
ktap
dtrace
kernel oops message
jvm crash
node.js/v8 crash

caller:

python traceback

Python was the only one I knew off-hand that is caller by default (and it includes the text "most recent call last", suggesting the developers thought it was necessary to point out that it was different). Do you know what tools/profilers/debuggers these users are using?

I really think people will be surprised if by default perf prints stacks differently to gdb, lldb, oops messages, etc, etc. That may be true for a specific developer community (eg, Python), but not for system profilers.

Brendan

Em Wed, Oct 21, 2015 at 11:28:54AM -0700, Brendan Gregg escreveu:

Quoted 58 lines · Chandler Carruth

Quoted 35 lines

Since Arnaldo asked, I thought I should actually try to respond specifically to the question of why I favor the 'caller' view as the default.

Quoted 10 lines · Arnaldo Carvalho de Melo

Quoted 4 lines

IMHO changing that order is not a good idea. Unless many users complained
about it.

Perhaps there are not that many users of callchains because the default is not what they're used to see?

Motivation for the change came from a video from Chandler, that resurfaced the callchain default issue, Chandler?

So, first and foremost, thanks for fixing some of my gripes about the usability of the perf tool, I'm super excited about the changes you're making, even if this one isn't among them.

I think the default of caller vs. callee is probably the hardest judgement call to make about the right defaults. I can see it going both ways.

When profiling my *system*, or a diverse group of programs or tasks, I often find callee useful. Were I a kernel developer, I suspect callee would be *dramatically* more common than caller.

For me, what makes the caller view much more frequently desired is that I'm usually profiling a fairly isolated application, or benchmark for an isolated library. While I always start off with some more system-level performance problem, I rarely need a detailed profile to get a reasonable idea of what subsystem to stare at, and then I spend days looking at a relatively isolated reproduction.

Quoted 2 lines

Anyways, for profiling user-land applications, I suspect from my conversations with users that "caller" is the more common expectation.

[...]

I would have said callee is the more common expectation, certainly for system profilers. I quickly checked various tools to see what their defaults are:

callee:

gdb
lldb
pstack
jstack
perf
stap
ktap
dtrace
kernel oops message
jvm crash
node.js/v8 crash

Quoted 3 lines

caller:

python traceback

sysprof -> http://sysprof.com/screen-shot-4.png

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Ingo, what do you think?

Quoted 4 lines

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Ingo, what do you think?

So I think the new default is a lot more intuitive, because it starts with a high level top-down 'overview' kind of output, allowing one to drill down to the details.

That's what most other tools do as well by default, and people migrating to perf found it pretty confusing that we do a bottom-up kind of callgraph.

To people using perf for the first time it does not matter nearly as much, but intuitiveness is still a factor.

The new default requires good call-chains and good symbol resolution to be maximally effective, but we want perfect callchains and symbols in any case, right?

Quoted 4 lines · Arnaldo Carvalho de Melo

Indeed, finding a default that is deemed adequate for most people is, ho-hum, difficult 8-)

Ingo, what do you think?

So I think the new default is a lot more intuitive, because it starts with a high level top-down 'overview' kind of output, allowing one to drill down to the details.

That's what most other tools do as well by default, and people migrating to perf found it pretty confusing that we do a bottom-up kind of callgraph. [...]

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

Quoted 19 lines · Brendan Gregg

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Quoted 8 lines

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

So I tried it:

triton:~/s/FlameGraph> ls -l flame.svg -rw-rw-r-- 1 mingo mingo 1022870 Oct 10 09:06 flame.svg

but when I tried to view it via ImageMagick, it first showed an empty screen:

triton:~/s/FlameGraph> display flame.svg

then when exiting it said:

display: non-conforming drawing primitive definition `text-anchor' @ error/draw.c/DrawImage/3182.

although I guess that latter is an unrealted ImageMagick problem, not caused by the SVG.

Quoted 44 lines · Ingo Molnar

Quoted 19 lines · Brendan Gregg

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, Oct 09, 2015 at 01:34:33PM -0700, Brendan Gregg escreveu:

Quoted 7 lines

Quoted 4 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 7 lines

Quoted 5 lines

Interactive tools, sure, like the perf report TUI.

But this also changes the ordering of the non-interactive tools which dump stacks: "perf report -n --stdio" and "perf script". The most common default for dumping stacks is caller. Eg:

And you use that for scripting?

Quoted 8 lines

Yes; how I typically CPU profile:

git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
perf record -F 99 -a -g -- sleep 60
perf script | ./stackcollapse-perf.pl | /flamegraph.pl > flame.svg

Then open flame.svg in a browser and click around. Try it. :)

So I tried it:

triton:~/s/FlameGraph> ls -l flame.svg -rw-rw-r-- 1 mingo mingo 1022870 Oct 10 09:06 flame.svg

but when I tried to view it via ImageMagick, it first showed an empty screen:

triton:~/s/FlameGraph> display flame.svg

then when exiting it said:

display: non-conforming drawing primitive definition `text-anchor' @ error/draw.c/DrawImage/3182.

Quoted 3 lines

although I guess that latter is an unrealted ImageMagick problem, not caused by the SVG.

Sorry, I should have said to open it in a browser (Chrome/Firefox); the SVG contains some (entirely embedded) JavaScript to provide interactivity (click to zoom, Ctrl-F to search).

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Requested-by Ingo Molnar <[email protected]>

Cc Adrian Hunter <[email protected]>

Cc Borislav Petkov <[email protected]>

Cc Chandler Carruth <[email protected]>

Cc David Ahern <[email protected]>

Cc Frederic Weisbecker <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Stephane Eranian <[email protected]>

Cc Wang Nan <[email protected]>

Link https://www.youtube.com/watch?v=nXaxk27zwlk

Link http://lkml.kernel.org/n/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/Documentation/perf-report.txt | 2 +-
 tools/perf/builtin-report.c              | 4 ++--
 tools/perf/util/util.c                   | 4 ++--
 3 files changed, 5 insertions(+), 5 deletions(-)

tools/perf/Documentation/perf-report.txt +1 -1

index ce499035e6d8..e4fdeeb51123 100644
@@ -192,7 +192,7 @@ OPTIONS
 	when available. Usually more convenient to use --branch-history
 	for this.
 
-	Default: fractal,0.5,callee,function.
+	Default: graph,0.5,caller
 
 --children::
 	Accumulate callchain of children to parent entry so that then can

tools/perf/builtin-report.c +0 -0

index b5623639f67d..3b23b25d1589 100644

tools/perf/builtin-report.c +1 -1

 	const char * const report_usage[] = {
 		"perf report [<options>]",
 		NULL

@@ -701,7 +701,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "Only display entries with parent-match"),
 	OPT_CALLBACK_DEFAULT('g', "call-graph", &report, "output_type,min_percent[,print_limit],call_order[,branch]",
 		     "Display callchains using output_type (graph, flat, fractal, or none) , min percent threshold, optional print limit, callchain order, key (function or address), add branches. "
-		     "Default: fractal,0.5,callee,function", &report_parse_callchain_opt, callchain_default_opt),
+		     "Default: graph,0.5,caller", &report_parse_callchain_opt, callchain_default_opt),
 	OPT_BOOLEAN(0, "children", &symbol_conf.cumulate_callchain,
 		    "Accumulate callchains of children and show total overhead as well"),
 	OPT_INTEGER(0, "max-stack", &report.max_stack,

tools/perf/util/util.c +0 -0

index ce465b259e52..c1bf9ff210b0 100644

tools/perf/util/util.c +1 -1

 	.min_percent = 0.5,
-	.order  = ORDER_CALLEE,
+	.order  = ORDER_CALLER,
 	.key	= CCKEY_FUNCTION
 };
 

Signature · 1 line

2.1.0

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Requested-by Ingo Molnar <[email protected]>

Cc Adrian Hunter <[email protected]>

Cc Borislav Petkov <[email protected]>

Cc Chandler Carruth <[email protected]>

Cc David Ahern <[email protected]>

Cc Frederic Weisbecker <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Stephane Eranian <[email protected]>

Cc Wang Nan <[email protected]>

Link https://www.youtube.com/watch?v=nXaxk27zwlk

Link http://lkml.kernel.org/n/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/Documentation/perf-report.txt | 2 +-
 tools/perf/builtin-report.c              | 4 ++--
 tools/perf/util/util.c                   | 4 ++--
 3 files changed, 5 insertions(+), 5 deletions(-)

tools/perf/Documentation/perf-report.txt +1 -1

index ce499035e6d8..e4fdeeb51123 100644
@@ -192,7 +192,7 @@ OPTIONS
 	when available. Usually more convenient to use --branch-history
 	for this.
 
-	Default: fractal,0.5,callee,function.
+	Default: graph,0.5,caller
 
 --children::
 	Accumulate callchain of children to parent entry so that then can

tools/perf/builtin-report.c +2 -2

index b5623639f67d..3b23b25d1589 100644
@@ -633,7 +633,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 	bool has_br_stack = false;
 	int branch_mode = -1;
 	bool branch_call_mode = false;
-	char callchain_default_opt[] = "fractal,0.5,callee";
+	char callchain_default_opt[] = "graph,0.5,caller";
 	const char * const report_usage[] = {
 		"perf report [<options>]",
 		NULL

@@ -701,7 +701,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "Only display entries with parent-match"),
 	OPT_CALLBACK_DEFAULT('g', "call-graph", &report, "output_type,min_percent[,print_limit],call_order[,branch]",
 		     "Display callchains using output_type (graph, flat, fractal, or none) , min percent threshold, optional print limit, callchain order, key (function or address), add branches. "
-		     "Default: fractal,0.5,callee,function", &report_parse_callchain_opt, callchain_default_opt),
+		     "Default: graph,0.5,caller", &report_parse_callchain_opt, callchain_default_opt),
 	OPT_BOOLEAN(0, "children", &symbol_conf.cumulate_callchain,
 		    "Accumulate callchains of children and show total overhead as well"),
 	OPT_INTEGER(0, "max-stack", &report.max_stack,

tools/perf/util/util.c +2 -2

index ce465b259e52..c1bf9ff210b0 100644
@@ -17,9 +17,9 @@
 #include "callchain.h"
 
 struct callchain_param	callchain_param = {
-	.mode	= CHAIN_GRAPH_REL,
+	.mode	= CHAIN_GRAPH_ABS,
 	.min_percent = 0.5,
-	.order  = ORDER_CALLEE,
+	.order  = ORDER_CALLER,
 	.key	= CCKEY_FUNCTION
 };
 

Signature · 1 line

2.1.0

Quoted 3 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

I think it's more useful to change the default only when --children is used. And there's a related issue too - please see below link:

https://lkml.org/lkml/2014/8/14/49

Quoted 5 lines · Namhyung Kim

Quoted 3 lines · Arnaldo Carvalho de Melo

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Quoted 4 lines

I think it's more useful to change the default only when --children is used. And there's a related issue too - please see below link:

https://lkml.org/lkml/2014/8/14/49

--children is default for things like "perf report --stdio" and (implied) "perf script", so any change to --children is a change to default.

From: Arnaldo Carvalho de Melo <[email protected]>

Which is the most common default found in other similar tools.

Requested-by Ingo Molnar <[email protected]>

Cc Adrian Hunter <[email protected]>

Cc Borislav Petkov <[email protected]>

Cc Chandler Carruth <[email protected]>

Cc David Ahern <[email protected]>

Cc Frederic Weisbecker <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Stephane Eranian <[email protected]>

Cc Wang Nan <[email protected]>

Link https://www.youtube.com/watch?v=nXaxk27zwlk

Link http://lkml.kernel.org/n/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
  tools/perf/Documentation/perf-report.txt | 2 +-
  tools/perf/builtin-report.c              | 4 ++--
  tools/perf/util/util.c                   | 4 ++--
  3 files changed, 5 insertions(+), 5 deletions(-)

tools/perf/Documentation/perf-report.txt +1 -1

index ce499035e6d8..e4fdeeb51123 100644
@@ -192,7 +192,7 @@ OPTIONS
  	when available. Usually more convenient to use --branch-history
  	for this.
 
-	Default: fractal,0.5,callee,function.
+	Default: graph,0.5,caller
 
  --children::
  	Accumulate callchain of children to parent entry so that then can

tools/perf/builtin-report.c +2 -2

index b5623639f67d..3b23b25d1589 100644
@@ -633,7 +633,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
  	bool has_br_stack = false;
  	int branch_mode = -1;
  	bool branch_call_mode = false;
-	char callchain_default_opt[] = "fractal,0.5,callee";
+	char callchain_default_opt[] = "graph,0.5,caller";
  	const char * const report_usage[] = {
  		"perf report [<options>]",
  		NULL

@@ -701,7 +701,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
  		    "Only display entries with parent-match"),
  	OPT_CALLBACK_DEFAULT('g', "call-graph", &report, "output_type,min_percent[,print_limit],call_order[,branch]",
  		     "Display callchains using output_type (graph, flat, fractal, or none) , min percent threshold, optional print limit, callchain order, key (function or address), add branches. "
-		     "Default: fractal,0.5,callee,function", &report_parse_callchain_opt, callchain_default_opt),
+		     "Default: graph,0.5,caller", &report_parse_callchain_opt, callchain_default_opt),
  	OPT_BOOLEAN(0, "children", &symbol_conf.cumulate_callchain,
  		    "Accumulate callchains of children and show total overhead as well"),
  	OPT_INTEGER(0, "max-stack", &report.max_stack,

tools/perf/util/util.c +2 -2

index ce465b259e52..c1bf9ff210b0 100644
@@ -17,9 +17,9 @@
  #include "callchain.h"
 
  struct callchain_param	callchain_param = {
-	.mode	= CHAIN_GRAPH_REL,
+	.mode	= CHAIN_GRAPH_ABS,
  	.min_percent = 0.5,
-	.order  = ORDER_CALLEE,
+	.order  = ORDER_CALLER,
  	.key	= CCKEY_FUNCTION
  };
 

Quoted 2 lines

From: Arnaldo Carvalho de Melo <[email protected]> Which is the most common default found in other similar tools.

Could you please show me some example about "other similar tools"? For me, in most of the case I prefer callee order because most of my task is to explain the reason why some code get executed too much times than expected.

Also, I think changing default settings should be careful.

This is my story: after switching to new version of perf, in a period of time there are plenty of perf users in my company be confused by the first column of 'perf report' because the sum of the percentage listed there is much higher than 100%. They find me because they think this is a bug in perf which breaks their routinely profiling work. The "problem" is caused by the adding of "--children". New perf makes '--children' as the default behavior at the first time it support that option, but the old perf shows things similar to '--no-children'. However, it is hard to explain the principle of call stack accumulation and why we need '--children' to those perf users (they learned perf's command line from others, and don't have enought to read perf documentations or even help output. Althought the title of the first column is changed to 'Children', I don't think they can understand the meaning of it. I think some of them didn't even notice there's an addition column in their output. They just confused and angry). Also, and as you can expect, this change breaks some scripts. In those days I have to make our IM tool response the information of "--no-children" automatically.

This patch changes the default output again. Similar thing will happen another time. I think this time I can make some preparation, for example, prepare new script to restore old behavior?

Thank you.

Quoted 66 lines

Requested-by Ingo Molnar <[email protected]>

Cc Adrian Hunter <[email protected]>

Cc Borislav Petkov <[email protected]>

Cc Chandler Carruth <[email protected]>

Cc David Ahern <[email protected]>

Cc Frederic Weisbecker <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Stephane Eranian <[email protected]>

Cc Wang Nan <[email protected]>

Link https://www.youtube.com/watch?v=nXaxk27zwlk

Link http://lkml.kernel.org/n/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/Documentation/perf-report.txt | 2 +-
 tools/perf/builtin-report.c              | 4 ++--
 tools/perf/util/util.c                   | 4 ++--
 3 files changed, 5 insertions(+), 5 deletions(-)

tools/perf/Documentation/perf-report.txt +1 -1

index ce499035e6d8..e4fdeeb51123 100644
@@ -192,7 +192,7 @@ OPTIONS
 	when available. Usually more convenient to use --branch-history
 	for this.
-	Default: fractal,0.5,callee,function.
+	Default: graph,0.5,caller
 --children::
 	Accumulate callchain of children to parent entry so that then can

tools/perf/builtin-report.c +2 -2

index b5623639f67d..3b23b25d1589 100644
@@ -633,7 +633,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 	bool has_br_stack = false;
 	int branch_mode = -1;
 	bool branch_call_mode = false;
-	char callchain_default_opt[] = "fractal,0.5,callee";
+	char callchain_default_opt[] = "graph,0.5,caller";
 	const char * const report_usage[] = {
 		"perf report [<options>]",
 		NULL

@@ -701,7 +701,7 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "Only display entries with parent-match"),
 	OPT_CALLBACK_DEFAULT('g', "call-graph", &report, "output_type,min_percent[,print_limit],call_order[,branch]",
 		     "Display callchains using output_type (graph, flat, fractal, or none) , min percent threshold, optional print limit, callchain order, key (function or address), add branches. "
-		     "Default: fractal,0.5,callee,function", &report_parse_callchain_opt, callchain_default_opt),
+		     "Default: graph,0.5,caller", &report_parse_callchain_opt, callchain_default_opt),
 	OPT_BOOLEAN(0, "children", &symbol_conf.cumulate_callchain,
 		    "Accumulate callchains of children and show total overhead as well"),
 	OPT_INTEGER(0, "max-stack", &report.max_stack,

tools/perf/util/util.c +2 -2

index ce465b259e52..c1bf9ff210b0 100644
@@ -17,9 +17,9 @@
 #include "callchain.h"
 struct callchain_param	callchain_param = {
-	.mode	= CHAIN_GRAPH_REL,
+	.mode	= CHAIN_GRAPH_ABS,
 	.min_percent = 0.5,
-	.order  = ORDER_CALLEE,
+	.order  = ORDER_CALLER,
 	.key	= CCKEY_FUNCTION
 };

Em Tue, Oct 20, 2015 at 09:23:12PM +0800, Wangnan (F) escreveu:

Quoted 30 lines · Arnaldo Carvalho de Melo

Quoted 2 lines

From: Arnaldo Carvalho de Melo <[email protected]> Which is the most common default found in other similar tools.

Could you please show me some example about "other similar tools"? For me, in most of the case I prefer callee order because most of my task is to explain the reason why some code get executed too much times than expected.

Also, I think changing default settings should be careful.

This is my story: after switching to new version of perf, in a period of time there are plenty of perf users in my company be confused by the first column of 'perf report' because the sum of the percentage listed there is much higher than 100%. They find me because they think this is a bug in perf which breaks their routinely profiling work. The "problem" is caused by the adding of "--children". New perf makes '--children' as the default behavior at the first time it support that option, but the old perf shows things similar to '--no-children'. However, it is hard to explain the principle of call stack accumulation and why we need '--children' to those perf users (they learned perf's command line from others, and don't have enought to read perf documentations or even help output. Althought the title of the first column is changed to 'Children', I don't think they can understand the meaning of it. I think some of them didn't even notice there's an addition column in their output. They just confused and angry). Also, and as you can expect, this change breaks some scripts. In those days I have to make our IM tool response the information of "--no-children" automatically.

Quoted 3 lines

This patch changes the default output again. Similar thing will happen another time. I think this time I can make some preparation, for example, prepare new script to restore old behavior?

I was bitten by the --children thing and took some time to get used to it, so I can relate to that...

I think we should revert this change in callchain default, enough complaints... Ingo, since you suggested that change, what are your thoughts?

Changing defaults is hard, there is also the horizontal scrolling that made we repurpose the right and left arrows, sigh, that one will cause some confusion as well...

It seems we'll need way more preparation for such changes, more infrastructure to ease the transition, questioning if the user wants that, etc, growing pains :-\

I was bitten by the --children thing and took some time to get used to it, so I can relate to that...

I think we should revert this change in callchain default, enough complaints... Ingo, since you suggested that change, what are your thoughts?

Quoted 6 lines

I was bitten by the --children thing and took some time to get used to it, so I can relate to that...

I think we should revert this change in callchain default, enough complaints... Ingo, since you suggested that change, what are your thoughts?

Btw., one side note, I noticed that the call-graph options to 'perf top' do not match that of perf report. I tried for a couple of minutes to figure out why this doesn't work:

perf top -g graph,0.5,caller

... only to notice that it's perf report options.

A couple of thoughts about defaults:

1)

I think 'perf top' and 'perf report' should provide the very same output by default. The two tools are unified, and we should think of 'perf top' more of a rolling, continuously updated perf report, with some dynamic runtime features that go beyond a simple perf report. Making them diverge only creates confusion.

2) min-percentage

I suspect the '0.5%' part of the default is not contested by anyone?

3) 'graph' vs. 'fractal'

The 'graph' part of the default: I think 'graph' (absolute percentages) is more intuitive in general than 'fractal' (relative percentages), especially when drilling down deep into more complex call graphs.

For example, if you look at this output:

                    |          |          |          |--41.61%-- local_apic_timer_interrupt
                    |          |          |          |          |          
                    |          |          |          |           --100.00%-- hrtimer_interrupt
                    |          |          |          |                     __run_hrtimer
                    |          |          |          |                     |          
                    |          |          |          |                     |--72.98%-- hrtimer_wakeup
                    |          |          |          |                     |          wake_up_process
                    |          |          |          |                     |          |          
                    |          |          |          |                     |           --100.00%-- try_to_wake_up
                    |          |          |          |                     |                     ttwu_do_activate.constprop.93
                    |          |          |          |                     |                     activate_task
                    |          |          |          |                     |                     enqueue_task
                    |          |          |          |                     |                     enqueue_task_fair
                    |          |          |          |                     |                     enqueue_entity
                    |          |          |          |                     |          
                    |          |          |          |                      --27.02%-- ehci_hrtimer_func

Would you have guessed that its relevance in reality is:

                    |          |          |          |          
                    |          |          |          |--0.11%-- local_apic_timer_interrupt
                    |          |          |          |          |          
                    |          |          |          |           --0.10%-- hrtimer_interrupt
                    |          |          |          |                     __run_hrtimer
                    |          |          |          |                     |          
                    |          |          |          |                     |--0.07%-- hrtimer_wakeup
                    |          |          |          |                     |          wake_up_process
                    |          |          |          |                     |          |          
                    |          |          |          |                     |           --0.01%-- try_to_wake_up
                    |          |          |          |                     |                     ttwu_do_activate.constprop.93
                    |          |          |          |                     |                     activate_task
                    |          |          |          |                     |                     enqueue_task
                    |          |          |          |                     |                     enqueue_task_fair
                    |          |          |          |                     |                     enqueue_entity
                    |          |          |          |                     |          
                    |          |          |          |                      --0.03%-- ehci_hrtimer_func
                    |          |          |          |          

?

I think the 'big picture' should always be apparent, even when looking at a small detail. Also, it's not _that_ hard to see the relative weight of each entry even if they are small numbers.

Fractal output can be useful if you are trying to drill down really, really deep and only concentrate on that aspect - but that kind of workflow is probably best served via a search option in any case:

  perf report --call-graph fractal,0.5,caller --stdio --symbol-filter local_apic_timer_interrupt

In which case fractal output is the more intuitive one I suspect:

# To display the perf.data header info, please use --header/--header-only options. #
#
# Total Lost Samples: 0
#
# Samples: 1K of event 'cycles:pp'
# Event count (approx.): 1155803425
#

  # Children      Self  Command  Shared Object      Symbol                        
  # ........  ........  .......  .................  ..............................

#
0.11% 0.01% swapper [kernel.kallsyms] [k] local_apic_timer_interrupt
|
|--89.19%-- local_apic_timer_interrupt
| hrtimer_interrupt
| __run_hrtimer
| |
| |--72.98%-- hrtimer_wakeup
| | wake_up_process
| | |
| | --100.00%-- try_to_wake_up
| | ttwu_do_activate.constprop.93
| | activate_task
| | enqueue_task
| | enqueue_task_fair
| | enqueue_entity
| |
| --27.02%-- ehci_hrtimer_func
|
--10.81%-- start_secondary
cpu_startup_entry cpuidle_enter apic_timer_interrupt smp_apic_timer_interrupt local_apic_timer_interrupt

#
# (For a higher level overview, try: perf report --sort comm,dso) #

Btw., I noticed an oddity, why doesn't "-S local_apic_timer_interrupt" produce any output? It was the first option I tried, and it only gave me:

triton:~/tip> perf report --call-graph fractal,0.5,caller --stdio -S local_apic_timer_interrupt [nv] with build id 744b5b4279152a54e61208989daf5d3d6b375aa3 not found, continuing without symbols Failed to open /tmp/perf-6650.map, continuing without symbols
# To display the perf.data header info, please use --header/--header-only options. #
# symbol: local_apic_timer_interrupt
#
# Total Lost Samples: 0
#
# Samples: 1K of event 'cycles:pp'
# Event count (approx.): 1155803425
#

  # Children      Self  Command  Shared Object
  # ........  ........  .......  .............

#

#
# (For a higher level overview, try: perf report --sort comm,dso) #

some symbols could not be found - but the output is pretty confusing and misleading in outputing just empty headers, plus it doesn't explain why it does so.

4) 'caller' vs. 'callee'.

If I change 'caller' to 'callee' in the above example, I get this output:

triton:~/tip> perf report --call-graph fractal,0.5,callee --stdio --symbol-filter local_apic_timer_interrupt [nv] with build id 744b5b4279152a54e61208989daf5d3d6b375aa3 not found, continuing without symbols Failed to open /tmp/perf-6650.map, continuing without symbols
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 1K of event 'cycles:pp'
# Event count (approx.): 1155803425
#

  # Children      Self  Command  Shared Object      Symbol                        
  # ........  ........  .......  .................  ..............................

#
0.11% 0.01% swapper [kernel.kallsyms] [k] local_apic_timer_interrupt
|
---local_apic_timer_interrupt
smp_apic_timer_interrupt
apic_timer_interrupt
cpuidle_enter
cpu_startup_entry
start_secondary

#
# (For a higher level overview, try: perf report --sort comm,dso) #

That does not look very helpful, does it?

Now I tried to test caller vs. callee in perf top - but couldn't find a command line option to do it - is there any?

5) --no-children

I agree that 'perf top -g --no-children' looks more intuitive than 'perf top -g'.

Em Wed, Oct 21, 2015 at 10:48:16AM +0200, Ingo Molnar escreveu:

Quoted 3 lines

5) --no-children

I agree that 'perf top -g --no-children' looks more intuitive than 'perf top -g'.

So, what do you propose, to switch back the default to --no-children, for both tools, top and report? Now that I am getting used to it... ;-)

Quoted 3 lines

5) --no-children

I agree that 'perf top -g --no-children' looks more intuitive than 'perf top -g'.

So, what do you propose, to switch back the default to --no-children, for both tools, top and report? Now that I am getting used to it... ;-)

Quoted 2 lines · Arnaldo Carvalho de Melo

Quoted 2 lines

5) --no-children

Quoted 4 lines

Quoted 1 line

I agree that 'perf top -g --no-children' looks more intuitive than 'perf top -g'.

So, what do you propose, to switch back the default to --no-children, for both tools, top and report? Now that I am getting used to it... ;-)

Heh ;-) So I'm only thinking out loud, trying to find the most intuitive initial screen to display. Expert users can configure their output any which way they want it to be, I'm not worried about them.

It's casual and in particular first-time users we should be worried about most - if they try the '-g' option in record, what will they first see in 'perf report' output?

I think the best output method would be to include only the 'highest level' parent symbols, with all children summed up under the parent's entry. Isn't the new 'graph,0.5,caller' default very close to that?

But what confuses me about the output is the same that confused Wangnan's users:

"This is my story: after switching to new version of perf, in a period of time
there are plenty of perf users in my company be confused by the first column of 'perf report' because the sum of the percentage listed there is much higher than 100%. They find me because they think this is a bug in perf which breaks their routinely profiling work."

So this is suboptimal.

The first column is 'Children', which should show the sum of all child overhead - but if a child overhead was already included under a parent, it should never show up under another parent's entry. I.e. the first column should only contain the highest level entries, no sub-entries.

But what we do currently is:

Children Self Command Shared Object Symbol

(quoted diff) +0 -2

-   70.41%     0.00%  cc1            cc1                 [.] toplev_main
   - toplev_main
      + __libc_start_main
-   70.38%     0.00%  cc1            libc-2.20.so        [.] __libc_start_main
   + __libc_start_main

i.e. even though '__libc_start_main' is a child of 'toplev_main', it's still included on the 'overview' page.

Is there an output method that can do what I suggest above?

( Having both 'children' and 'self' columns in itself is intuitive IMHO: it shows
that an entry that is shown does not directly have overhead at that level, a child call of it has that overhead. )

Thanks,

Ingo

Hi Ingo,

Please consider pulling,

- Arnaldo

The following changes since commit e3b0ac1b7a8a590440a2030e7d10d48c59ab8a2a:

Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core (2015-10-03 08:20:14 +0200)

are available in the git repository at:

git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git tags/perf-core-for-mingo

for you to fetch changes up to 27bf90bf0690f55c3679bcc4c325823cf1cfd19d:

perf tools: Fail properly in case pattern matching fails to find tracepoint (2015-10-05 17:59:50 -0300)

----------------------------------------------------------------
perf/core improvements and fixes:

User visible:

- Switch the default callchain output mode to 'graph,0.5,caller', to make it look like the default for other tools, reducing the learning curve for people used to 'caller' based viewing (Arnaldo Carvalho de Melo)

- Implement column based horizontal scrolling in the hists browser (top, report), making it possible to use the TUI for things like 'perf mem report' where there are many more columns than can fit in a terminal (Arnaldo Carvalho de Melo)

- Support sorting by symbol_iaddr with perf.data files produced by 'perf mem record' (Don Zickus)

- Display DATA_SRC sample type bit, i.e. when running 'perf evlist -v' the "DATA_SRC" wasn't appearing when set, fix it to look like: (Jiri Olsa)

cpu/mem-loads/pp: ...SNIP... sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|DATA_SRC

- Introduce 'P' event modified, meaning 'max precision level, please', i.e.:

   $ perf record -e cycles:P usleep 1

Is now similar to:

   $ perf record usleep 1

Useful, for instance, when specifying multiple events (Jiri Olsa)

- Make 'perf -v' and 'perf -h' work (Jiri Olsa)

- Fail properly when pattern matching fails to find a tracepoint, i.e. '-e non:existent' was being correctly handled, with a proper error message about that not being a valid event, but '-e non:existent*' wasn't, fix it (Jiri Olsa)

Infrastructure:

- Separate arch specific entries in 'perf test' and add an 'Intel CQM' one to be fun on x86 only (Matt Fleming)

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

----------------------------------------------------------------
Arnaldo Carvalho de Melo (3):
perf callchain: Switch default to 'graph,0.5,caller' perf ui browser: Optional horizontal scrolling key binding perf hists browser: Implement horizontal scrolling

Don Zickus (1):
perf tools: Add support for sorting on the iaddr

Jiri Olsa (9):
tools lib api fs: No need to use PATH_MAX + 1
perf evlist: Display DATA_SRC sample type bit
perf annotate: Fix sizeof_sym_hist overflow issue
perf tools: Export perf_event_attr__set_max_precise_ip()
perf tools: Introduce 'P' modifier to request max precision perf tests: Add parsing test for 'P' modifier
perf tools: Setup proper width for symbol_iaddr field
perf tools: Handle -h and -v options
perf tools: Fail properly in case pattern matching fails to find tracepoint

Matt Fleming (3):
perf tests: Add arch tests
perf tests: Move x86 tests into arch directory perf tests: Add Intel CQM test

 tools/lib/api/fs/fs.c                              |   2 +-
 tools/lib/api/fs/tracing_path.c                    |   6 +-
 tools/perf/Documentation/perf-list.txt             |   1 +
 tools/perf/Documentation/perf-report.txt           |   2 +-
 tools/perf/Documentation/perf.txt                  |   8 ++
 tools/perf/arch/x86/Build                          |   2 +-
 tools/perf/arch/x86/include/arch-tests.h           |  19 ++++
 tools/perf/arch/x86/tests/Build                    |  10 +-
 tools/perf/arch/x86/tests/arch-tests.c             |  34 ++++++
 tools/perf/arch/x86/tests/dwarf-unwind.c           |   1 +
 .../perf/{ => arch/x86}/tests/gen-insn-x86-dat.awk |   0
 .../perf/{ => arch/x86}/tests/gen-insn-x86-dat.sh  |   0
 tools/perf/{ => arch/x86}/tests/insn-x86-dat-32.c  |   0
 tools/perf/{ => arch/x86}/tests/insn-x86-dat-64.c  |   0
 tools/perf/{ => arch/x86}/tests/insn-x86-dat-src.c |   0
 tools/perf/{ => arch/x86}/tests/insn-x86.c         |   3 +-
 tools/perf/arch/x86/tests/intel-cqm.c              | 124 +++++++++++++++++++++
 tools/perf/{ => arch/x86}/tests/perf-time-to-tsc.c |   4 +-
 tools/perf/{ => arch/x86}/tests/rdpmc.c            |   7 +-
 tools/perf/builtin-report.c                        |   4 +-
 tools/perf/perf.c                                  |  14 +++
 tools/perf/tests/Build                             |   6 -
 tools/perf/tests/builtin-test.c                    |  56 ++++------
 tools/perf/tests/dwarf-unwind.c                    |   4 +
 tools/perf/tests/parse-events.c                    |  16 +++
 tools/perf/tests/tests.h                           |  10 +-
 tools/perf/ui/browser.c                            |  14 +++
 tools/perf/ui/browser.h                            |   2 +-
 tools/perf/ui/browsers/hists.c                     |  22 +++-
 tools/perf/util/annotate.h                         |   2 +-
 tools/perf/util/evlist.c                           |   2 +-
 tools/perf/util/evlist.h                           |   2 +
 tools/perf/util/evsel.c                            |   5 +-
 tools/perf/util/evsel.h                            |   1 +
 tools/perf/util/hist.c                             |  13 +++
 tools/perf/util/hist.h                             |   1 +
 tools/perf/util/parse-events.c                     |  17 ++-
 tools/perf/util/parse-events.l                     |   2 +-
 tools/perf/util/sort.c                             |  37 ++++++
 tools/perf/util/sort.h                             |   1 +
 tools/perf/util/util.c                             |   4 +-
 41 files changed, 381 insertions(+), 77 deletions(-)
 create mode 100644 tools/perf/arch/x86/include/arch-tests.h
 create mode 100644 tools/perf/arch/x86/tests/arch-tests.c
 rename tools/perf/{ => arch/x86}/tests/gen-insn-x86-dat.awk (100%)

 rename tools/perf/{ => arch/x86}/tests/gen-insn-x86-dat.sh (100%)
 rename tools/perf/{ => arch/x86}/tests/insn-x86-dat-32.c (100%)
 rename tools/perf/{ => arch/x86}/tests/insn-x86-dat-64.c (100%)
 rename tools/perf/{ => arch/x86}/tests/insn-x86-dat-src.c (100%)
 rename tools/perf/{ => arch/x86}/tests/insn-x86.c (98%)
 create mode 100644 tools/perf/arch/x86/tests/intel-cqm.c
 rename tools/perf/{ => arch/x86}/tests/perf-time-to-tsc.c (98%)
 rename tools/perf/{ => arch/x86}/tests/rdpmc.c (97%)