From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932215AbbJUIs0 (ORCPT ); Wed, 21 Oct 2015 04:48:26 -0400 Received: from mail-wi0-f174.google.com ([209.85.212.174]:32880 "EHLO mail-wi0-f174.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753201AbbJUIsX (ORCPT ); Wed, 21 Oct 2015 04:48:23 -0400 Date: Wed, 21 Oct 2015 10:48:16 +0200 From: Ingo Molnar To: Arnaldo Carvalho de Melo Cc: "Wangnan (F)" , Arnaldo Carvalho de Melo , linux-kernel@vger.kernel.org, Adrian Hunter , Borislav Petkov , Chandler Carruth , David Ahern , Frederic Weisbecker , Jiri Olsa , Namhyung Kim , Stephane Eranian , pi3orama Subject: Re: [PATCH 13/16] perf callchain: Switch default to 'graph,0.5,caller' Message-ID: <20151021084816.GA12992@gmail.com> References: <1444079018-31421-1-git-send-email-acme@kernel.org> <1444079018-31421-14-git-send-email-acme@kernel.org> <56264040.20708@huawei.com> <20151020133816.GD4400@redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20151020133816.GD4400@redhat.com> User-Agent: Mutt/1.5.23 (2014-03-12) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org * Arnaldo Carvalho de Melo wrote: > 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'. Thanks, Ingo