[PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Namhyung Kim]

Currently perf report on TUI doesn't print percent for first-level
callchain entry.  I guess it (wrongly) assumes that there's only a
single callchain in the first level.  This patch fixes it by handling
the first level callchains same as others - if it's not 100% it should
print the percent value.  Also it'll affect other callchains in the
other way around - if it's 100% (single callchain) it should not print
the percentage.

Before:
  -   30.95%     6.84%  abc2     abc2              [.] a
     - a
        - 70.00% c
           - 100.00% apic_timer_interrupt
                smp_apic_timer_interrupt
                local_apic_timer_interrupt
                hrtimer_interrupt
                ...
        + 30.00% b
     + __libc_start_main

After:
  -   30.95%     6.84%  abc2     abc2              [.] a
     - 77.90% a
        - 70.00% c
           - apic_timer_interrupt
             smp_apic_timer_interrupt
             local_apic_timer_interrupt
             hrtimer_interrupt
             ...
        + 30.00% b
     + 22.10% __libc_start_main

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/ui/browsers/hists.c | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 12c17c5a3d68..8d22905a4687 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -542,8 +542,11 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 	struct rb_node *node;
 	int first_row = row, offset = level * LEVEL_OFFSET_STEP;
 	u64 new_total;
+	bool need_percent;
 
 	node = rb_first(root);
+	need_percent = !!rb_next(node);
+
 	while (node) {
 		struct callchain_node *child = rb_entry(node, struct callchain_node, rb_node);
 		struct rb_node *next = rb_next(node);
@@ -560,7 +563,7 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 
 			if (first)
 				first = false;
-			else if (level > 1)
+			else if (need_percent)
 				extra_offset = LEVEL_OFFSET_STEP;
 
 			folded_sign = callchain_list__folded(chain);
@@ -573,7 +576,7 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 			str = callchain_list__sym_name(chain, bf, sizeof(bf),
 						       browser->show_dso);
 
-			if (was_first && level > 1) {
+			if (was_first && need_percent) {
 				double percent = cumul * 100.0 / total;
 
 				if (asprintf(&alloc_str, "%2.2f%% %s", percent, str) < 0)
@@ -790,6 +793,13 @@ static int hist_browser__show_entry(struct hist_browser *browser,
 			.is_current_entry = current_entry,
 		};
 
+		if (callchain_param.mode == CHAIN_GRAPH_REL) {
+			if (symbol_conf.cumulate_callchain)
+				total = entry->stat_acc->period;
+			else
+				total = entry->stat.period;
+		}
+
 		printed += hist_browser__show_callchain(browser,
 					&entry->sorted_chain, 1, row, total,
 					hist_browser__show_callchain_entry, &arg,
-- 
2.1.2

[PATCH 2/2] perf tools: Collapse first level callchain entry if it has sibling

[Namhyung Kim]

If first level callchain has more than single path like when -g caller
option is given, it should show only first one in the path and hide
others.  But it didn't do it properly nad just hindered the output.

Before:
  -   80.33%    11.11%  abc2     abc2              [.] main
     + 86.18% main
       13.82% __libc_start_main
          main

After:
  -   80.33%    11.11%  abc2     abc2              [.] main
     + 86.18% main
     + 13.82% __libc_start_main

Cc: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/ui/browsers/hists.c | 11 ++++++++---
 1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 8d22905a4687..502daff76ceb 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -227,10 +227,14 @@ static void callchain_node__init_have_children_rb_tree(struct callchain_node *no
 	}
 }
 
-static void callchain_node__init_have_children(struct callchain_node *node)
+static void callchain_node__init_have_children(struct callchain_node *node,
+					       bool has_sibling)
 {
 	struct callchain_list *chain;
 
+	chain = list_entry(node->val.next, struct callchain_list, list);
+	chain->ms.has_children = has_sibling;
+
 	if (!list_empty(&node->val)) {
 		chain = list_entry(node->val.prev, struct callchain_list, list);
 		chain->ms.has_children = !RB_EMPTY_ROOT(&node->rb_root);
@@ -241,11 +245,12 @@ static void callchain_node__init_have_children(struct callchain_node *node)
 
 static void callchain__init_have_children(struct rb_root *root)
 {
-	struct rb_node *nd;
+	struct rb_node *nd = rb_first(root);
+	bool has_sibling = nd && rb_next(nd);
 
 	for (nd = rb_first(root); nd; nd = rb_next(nd)) {
 		struct callchain_node *node = rb_entry(nd, struct callchain_node, rb_node);
-		callchain_node__init_have_children(node);
+		callchain_node__init_have_children(node, has_sibling);
 	}
 }
 
-- 
2.1.2

probe + report for following branch history. was Re: [PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 05:13:26PM +0900, Namhyung Kim escreveu:
> Currently perf report on TUI doesn't print percent for first-level
> callchain entry.  I guess it (wrongly) assumes that there's only a
> single callchain in the first level.  This patch fixes it by handling
> the first level callchains same as others - if it's not 100% it should
> print the percent value.  Also it'll affect other callchains in the
> other way around - if it's 100% (single callchain) it should not print
> the percentage.
> 
> Before:
>   -   30.95%     6.84%  abc2     abc2              [.] a
>      - a

Thanks, with this the --stdio output matches --tui when --branch-history
is used in 'report', will push soon.

One thing I think would be great would be to make it possible to use:

  [root@zoo acme]# perf probe -L get_vma_policy
  <get_vma_policy@/usr/src/debug/kernel-3.17.fc20/linux-3.17.2-200.fc20.x86_64/mm/mempolicy.c:0>
        0  struct mempolicy *get_vma_policy(struct task_struct *task,
                          struct vm_area_struct *vma, unsigned long addr)
        2  {
        3         struct mempolicy *pol = get_task_policy(task);
           
        5         if (vma) {
        6                 if (vma->vm_ops && vma->vm_ops->get_policy) {
        7                         struct mempolicy *vpol = vma->vm_ops->get_policy(vma,
                                                                                  addr);
        9                         if (vpol)
                                          pol = vpol;
       11                 } else if (vma->vm_policy) {
                                  pol = vma->vm_policy;
         
                                  /*
                                   * shmem_alloc_page() passes
                                   * MPOL_F_SHARED policy with
                                   * a pseudo vma whose vma->vm_ops=NULL.
                                   * Take a reference
                                   * count on these policies which will be
                                   * dropped by
                                   * mpol_cond_put() later
                                   */
       20                         if (mpol_needs_cond_ref(pol))
       21                                 mpol_get(pol);
                          }
                  }
                  if (!pol)
                          pol = &default_policy;
                  return pol;
       27  }
         
  [root@zoo acme]#

Together with the srcline code, i.e. to allow matching the above with
the output from 'perf report', like here:

     2.40%  mmzone.c:69  [k] next_zones_zonelist            [kernel.vmlinux]
            |
            ---next_zones_zonelist mmzone.c:59
               __alloc_pages_nodemask mmzone.h:1039
               __alloc_pages_nodemask page_alloc.c:2775
               __alloc_pages_nodemask page_alloc.c:2765
               __alloc_pages_nodemask page_alloc.c:2765
               _cond_resched core.c:4180
               _cond_resched core.c:4175
               __alloc_pages_nodemask page_alloc.c:2765
               __alloc_pages_nodemask page_alloc.c:2765
               __alloc_pages_nodemask page_alloc.c:2765
               __alloc_pages_nodemask page_alloc.c:2751
               alloc_pages_vma mempolicy.c:2046
               alloc_pages_vma mempolicy.c:2046
               policy_zonelist mempolicy.c:1735
               policy_zonelist gfp.h:274
               policy_zonelist mempolicy.c:1717
               policy_zonelist mempolicy.c:1717
               policy_zonelist mempolicy.c:1715
               policy_zonelist mempolicy.c:1714
               alloc_pages_vma mempolicy.c:2046
               alloc_pages_vma mempolicy.c:2046
               policy_nodemask mempolicy.c:1709
               policy_nodemask mempolicy.c:1701
               alloc_pages_vma mempolicy.c:2046
               alloc_pages_vma seqlock.h:111
               get_vma_policy mempolicy.c:1650
               get_vma_policy mempolicy.c:1650
               get_vma_policy mempolicy.c:1634
               get_vma_policy mempolicy.c:1634
               get_vma_policy mempolicy.c:1629
               get_vma_policy mempolicy.c:1628
               get_vma_policy mempolicy.c:134

See the get_vma_policy lines? We need a way to ask both for 'perf probe -L' to
show absolute line numbers and also for the report code to show line numbers as
offsets from function start.

At some point being able to, as IIRC Andi suggested, to show the callchains via
the annotate widget would be fantastic as well, i.e. showing the callchain in a
window and in another window to show it as arrows in the source code, that
would move from function to function as we navigate on the callchain, as we
do already with jumps, calls, rets.

But the absolute line numbers on 'perf probe -L' and the offsets from function
start in 'report' look like low hanging fruits and a way to integrate further
'perf probe' with 'perf report', because both will look at the right file, keyed
by the build-id, etc.

- Arnaldo

Re: probe + report for following branch history. was Re: [PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 11:52:27AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Mon, Nov 24, 2014 at 05:13:26PM +0900, Namhyung Kim escreveu:
> > Currently perf report on TUI doesn't print percent for first-level
> > callchain entry.  I guess it (wrongly) assumes that there's only a
> > single callchain in the first level.  This patch fixes it by handling
> > the first level callchains same as others - if it's not 100% it should
> > print the percent value.  Also it'll affect other callchains in the
> > other way around - if it's 100% (single callchain) it should not print
> > the percentage.
> > 
> > Before:
> >   -   30.95%     6.84%  abc2     abc2              [.] a
> >      - a
> 
> Thanks, with this the --stdio output matches --tui when --branch-history
> is used in 'report', will push soon.

[acme@zoo linux]$ time make -C tools/perf build-test
make: Entering directory `/home/git/linux/tools/perf'
- make_pure: cd . && make -f Makefile DESTDIR=/tmp/tmp.z11aKMiurz 
- make_clean_all: cd . && make -f Makefile DESTDIR=/tmp/tmp.aylbvfzj5m
  clean all
- make_python_perf_so: cd . && make -f Makefile
  DESTDIR=/tmp/tmp.t896NZcPrJ python/perf.so
- make_debug: cd . && make -f Makefile DESTDIR=/tmp/tmp.ARnUdN0Ox5
  DEBUG=1
- make_no_libperl: cd . && make -f Makefile DESTDIR=/tmp/tmp.xG1XJ2Pjq7
  NO_LIBPERL=1
- make_no_libpython: cd . && make -f Makefile
  DESTDIR=/tmp/tmp.2k8q3ouduH NO_LIBPYTHON=1
- make_no_scripts: cd . && make -f Makefile DESTDIR=/tmp/tmp.kwu6TUzMaZ
  NO_LIBPYTHON=1 NO_LIBPERL=1
- make_no_newt: cd . && make -f Makefile DESTDIR=/tmp/tmp.Ra0cHpOVXI
  NO_NEWT=1
- make_no_slang: cd . && make -f Makefile DESTDIR=/tmp/tmp.dI5pMO80Gw
  NO_SLANG=1
- make_no_gtk2: cd . && make -f Makefile DESTDIR=/tmp/tmp.r4R7rILIq4
  NO_GTK2=1
- make_no_ui: cd . && make -f Makefile DESTDIR=/tmp/tmp.36qCtqcT3J
  NO_NEWT=1 NO_SLANG=1 NO_GTK2=1
- make_no_demangle: cd . && make -f Makefile DESTDIR=/tmp/tmp.5PpSkaVWUl
  NO_DEMANGLE=1
cd . && make -f Makefile DESTDIR=/tmp/tmp.5PpSkaVWUl NO_DEMANGLE=1
  BUILD:   Doing 'make -j4' parallel build

Auto-detecting system features:
...                         dwarf: [ on  ]
...                         glibc: [ on  ]
...                          gtk2: [ on  ]
...                      libaudit: [ on  ]
...                        libbfd: [ on  ]
...                        libelf: [ on  ]
...                       libnuma: [ on  ]
...                       libperl: [ on  ]
...                     libpython: [ on  ]
...                      libslang: [ on  ]
...                     libunwind: [ on  ]
...            libdw-dwarf-unwind: [ on  ]
...                          zlib: [ on  ]
...     DWARF post unwind library: libunwind

  GEN      common-cmds.h
  FLAGS:   * new build flags or prefix
  BISON    util/pmu-bison.c
  CC       util/environment.o
  CC       util/event.o
  CC       util/evlist.o
  CC       util/evsel.o
  PERF_VERSION = 3.18.rc3.gf07177
  CC       util/exec_cmd.o
  CC       util/help.o
  CC       util/kallsyms.o
  CC       util/levenshtein.o
  CC       util/parse-options.o
  BISON    util/parse-events-bison.c
  CC       util/path.o
  CC       util/rbtree.o
  CC       util/bitmap.o
  CC       util/hweight.o
  CC       util/run-command.o
  CC       util/quote.o
  CC       util/strbuf.o
  CC       util/string.o
  CC       util/strlist.o
  CC       util/strfilter.o
  CC       util/top.o
  CC       util/usage.o
  CC       util/wrapper.o
  CC       util/sigchain.o
  CC       util/dso.o
  CC       util/symbol.o
  CC       util/symbol-elf.o
  CC       util/color.o
  CC       util/pager.o
  CC       util/header.o
  CC       util/callchain.o
  CC       util/values.o
  CC       util/debug.o
  CC       util/machine.o
  CC       util/map.o
  CC       util/pstack.o
  CC       util/session.o
  CC       util/ordered-events.o
  CC       util/comm.o
  CC       util/thread.o
  CC       util/thread_map.o
  CC       util/trace-event-parse.o
  CC       util/parse-events-bison.o
  CC       util/pmu-bison.o
  CC       util/trace-event-read.o
  CC       util/trace-event-info.o
  CC       util/trace-event-scripting.o
  CC       util/trace-event.o
  CC       util/svghelper.o
  CC       util/sort.o
  CC       util/hist.o
  CC       util/probe-event.o
  CC       util/util.o
  CC       util/xyarray.o
  CC       util/cpumap.o
  CC       util/cgroup.o
  CC       util/target.o
  CC       util/rblist.o
  CC       util/intlist.o
  CC       util/vdso.o
  CC       util/stat.o
  CC       util/record.o
  CC       util/srcline.o
  CC       util/data.o
  CC       util/tsc.o
  CC       util/cloexec.o
In file included from util/srcline.c:18:0:
/usr/include/bfd.h:6197:7: error: conflicting types for ‘bfd_demangle’
 char *bfd_demangle (bfd *, const char *, int);
       ^
In file included from util/srcline.c:11:0:
util/symbol.h:35:21: note: previous definition of ‘bfd_demangle’ was
here
 static inline char *bfd_demangle(void __maybe_unused *v,
                     ^
make[3]: *** [util/srcline.o] Error 1
make[3]: *** Waiting for unfinished jobs....
make[2]: *** [all] Error 2
  test: test -x ./perf
make[1]: *** [make_no_demangle] Error 1
make: *** [build-test] Error 2
make: Leaving directory `/home/git/linux/tools/perf'

real	4m21.797s
user	10m54.214s
sys	1m26.056s
[acme@zoo linux]$

Re: probe + report for following branch history. was Re: [PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 12:23:12PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Mon, Nov 24, 2014 at 11:52:27AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Mon, Nov 24, 2014 at 05:13:26PM +0900, Namhyung Kim escreveu:
> > > Currently perf report on TUI doesn't print percent for first-level
> > > callchain entry.  I guess it (wrongly) assumes that there's only a
> > > single callchain in the first level.  This patch fixes it by handling
> > > the first level callchains same as others - if it's not 100% it should
> > > print the percent value.  Also it'll affect other callchains in the
> > > other way around - if it's 100% (single callchain) it should not print
> > > the percentage.
> > > 
> > > Before:
> > >   -   30.95%     6.84%  abc2     abc2              [.] a
> > >      - a
> > 
> > Thanks, with this the --stdio output matches --tui when --branch-history
> > is used in 'report', will push soon.
> 
> [acme@zoo linux]$ time make -C tools/perf build-test
> make: Entering directory `/home/git/linux/tools/perf'
> - make_pure: cd . && make -f Makefile DESTDIR=/tmp/tmp.z11aKMiurz 

Right to the point:

[acme@zoo linux]$ make -C tools/perf NO_DEMANGLE=1 util/srcline.o
make: Entering directory `/home/git/linux/tools/perf'
  BUILD:   Doing 'make -j4' parallel build
  CC       util/srcline.o
In file included from util/srcline.c:18:0:
/usr/include/bfd.h:6197:7: error: conflicting types for ‘bfd_demangle’
 char *bfd_demangle (bfd *, const char *, int);
       ^
In file included from util/srcline.c:11:0:
util/symbol.h:35:21: note: previous definition of ‘bfd_demangle’ was
here
 static inline char *bfd_demangle(void __maybe_unused *v,
                     ^
make[1]: *** [util/srcline.o] Error 1
make: *** [util/srcline.o] Error 2
make: Leaving directory `/home/git/linux/tools/perf'
[acme@zoo linux]$ 

Re: probe + report for following branch history. was Re: [PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 12:25:41PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Mon, Nov 24, 2014 at 12:23:12PM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Mon, Nov 24, 2014 at 11:52:27AM -0300, Arnaldo Carvalho de Melo escreveu:
> > > Em Mon, Nov 24, 2014 at 05:13:26PM +0900, Namhyung Kim escreveu:
> > > > Currently perf report on TUI doesn't print percent for first-level
> > > > callchain entry.  I guess it (wrongly) assumes that there's only a
> > > > single callchain in the first level.  This patch fixes it by handling
> > > > the first level callchains same as others - if it's not 100% it should
> > > > print the percent value.  Also it'll affect other callchains in the
> > > > other way around - if it's 100% (single callchain) it should not print
> > > > the percentage.
> > > > 
> > > > Before:
> > > >   -   30.95%     6.84%  abc2     abc2              [.] a
> > > >      - a
> > > 
> > > Thanks, with this the --stdio output matches --tui when --branch-history
> > > is used in 'report', will push soon.
> > 
> > [acme@zoo linux]$ time make -C tools/perf build-test
> > make: Entering directory `/home/git/linux/tools/perf'
> > - make_pure: cd . && make -f Makefile DESTDIR=/tmp/tmp.z11aKMiurz 
> 
> Right to the point:
> 
> [acme@zoo linux]$ make -C tools/perf NO_DEMANGLE=1 util/srcline.o
> make: Entering directory `/home/git/linux/tools/perf'
>   BUILD:   Doing 'make -j4' parallel build
>   CC       util/srcline.o
> In file included from util/srcline.c:18:0:
> /usr/include/bfd.h:6197:7: error: conflicting types for ‘bfd_demangle’
>  char *bfd_demangle (bfd *, const char *, int);
>        ^
> In file included from util/srcline.c:11:0:
> util/symbol.h:35:21: note: previous definition of ‘bfd_demangle’ was
> here
>  static inline char *bfd_demangle(void __maybe_unused *v,
>                      ^
> make[1]: *** [util/srcline.o] Error 1
> make: *** [util/srcline.o] Error 2
> make: Leaving directory `/home/git/linux/tools/perf'
> [acme@zoo linux]$ 

bisected it down to:

43e3229ef07a2dda81bda86a5b81ef8c2890ab63 is the first bad commit
commit 43e3229ef07a2dda81bda86a5b81ef8c2890ab63
Author: Andi Kleen <ak@linux.intel.com>
Date:   Wed Nov 12 18:05:27 2014 -0800

    perf callchain: Make get_srcline fall back to sym+offset
    
    When the source line is not found fall back to sym + offset.  This is
    generally much more useful than a raw address.
    
    For this we need to pass in the symbol from the caller.
    
    For some callers it's awkward to compute, so we stay at the old
    behaviour.
    
    Signed-off-by: Andi Kleen <ak@linux.intel.com>
    Cc: Jiri Olsa <jolsa@redhat.com>
    Cc: Namhyung Kim <namhyung@kernel.org>
    Link: http://lkml.kernel.org/r/1415844328-4884-10-git-send-email-andi@firstfloor.org
    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

:040000 040000 ae5e95c8dbfd9ab8e836707fcb2904e263f872c6
5979ba316f1d317c59866b0c3bf92c39fbdcde6b M	tools
[acme@zoo linux]$

perf/branch-history branch build broken with NO_DEMANGLE=1 perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 12:32:04PM -0300, Arnaldo Carvalho de Melo escreveu:
> >        ^
> > In file included from util/srcline.c:11:0:
> > util/symbol.h:35:21: note: previous definition of ‘bfd_demangle’ was
> > here
> >  static inline char *bfd_demangle(void __maybe_unused *v,
> >                      ^
> > make[1]: *** [util/srcline.o] Error 1
> > make: *** [util/srcline.o] Error 2
> > make: Leaving directory `/home/git/linux/tools/perf'
> > [acme@zoo linux]$ 
> 
> bisected it down to:

What I have is on the perf/branch-history branch, we can't both include
bfd.h and symbol.h when NO_DEMANGLE=1, probably we should just move the
stub inline to symbol-elf.c, its only user, but I have to check further,
lunch time tho.

- Arnaldo
 
> 43e3229ef07a2dda81bda86a5b81ef8c2890ab63 is the first bad commit
> commit 43e3229ef07a2dda81bda86a5b81ef8c2890ab63
> Author: Andi Kleen <ak@linux.intel.com>
> Date:   Wed Nov 12 18:05:27 2014 -0800
> 
>     perf callchain: Make get_srcline fall back to sym+offset
>     
>     When the source line is not found fall back to sym + offset.  This is
>     generally much more useful than a raw address.
>     
>     For this we need to pass in the symbol from the caller.
>     
>     For some callers it's awkward to compute, so we stay at the old
>     behaviour.
>     
>     Signed-off-by: Andi Kleen <ak@linux.intel.com>
>     Cc: Jiri Olsa <jolsa@redhat.com>
>     Cc: Namhyung Kim <namhyung@kernel.org>
>     Link: http://lkml.kernel.org/r/1415844328-4884-10-git-send-email-andi@firstfloor.org
>     Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> 
> :040000 040000 ae5e95c8dbfd9ab8e836707fcb2904e263f872c6
> 5979ba316f1d317c59866b0c3bf92c39fbdcde6b M	tools
> [acme@zoo linux]$

Re: perf/branch-history branch build broken with NO_DEMANGLE=1 perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 12:48:41PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Mon, Nov 24, 2014 at 12:32:04PM -0300, Arnaldo Carvalho de Melo escreveu:
> > >        ^
> > > In file included from util/srcline.c:11:0:
> > > util/symbol.h:35:21: note: previous definition of ‘bfd_demangle’ was
> > > here
> > >  static inline char *bfd_demangle(void __maybe_unused *v,
> > >                      ^
> > > make[1]: *** [util/srcline.o] Error 1
> > > make: *** [util/srcline.o] Error 2
> > > make: Leaving directory `/home/git/linux/tools/perf'
> > > [acme@zoo linux]$ 
> > 
> > bisected it down to:
> 
> What I have is on the perf/branch-history branch, we can't both include
> bfd.h and symbol.h when NO_DEMANGLE=1, probably we should just move the
> stub inline to symbol-elf.c, its only user, but I have to check further,
> lunch time tho.

Fixed, pushed it out on my perf/core and perf/branch-history branches.

--branch-history stuff still on a separate branch because it explodes:

[root@zoo acme]# perf record -a -g -b sleep 2s
[ perf record: Woken up 7 times to write data ]
[ perf record: Captured and wrote 3.033 MB perf.data (~132504 samples) ]
[root@zoo acme]# perf report --stdio --branch-history
# To display the perf.data header info, please use --header/--header-only options.
#
BFD: Dwarf Error: Offset (2585882475) greater than or equal to .debug_str size (44321517).
BFD: Dwarf Error: Could not find abbrev number 11800.
<BIG SNIP>
BFD: Dwarf Error: Offset (83496016) greater than or equal to .debug_str size (44321517).
BFD: Dwarf Error: Offset (48628447) greater than or equal to .debug_str size (44321517).
(END)Segmentation fault (core dumped)
[root@zoo acme]# 

Will investigate this later today/tomorrow, if nobody finds a fix in the meantime.

- Arnaldo

Re: perf/branch-history branch build broken with NO_DEMANGLE=1 perf hists browser: Print overhead percent value for first-level callchain

[Andi Kleen]

> [root@zoo acme]# perf record -a -g -b sleep 2s
> [ perf record: Woken up 7 times to write data ]
> [ perf record: Captured and wrote 3.033 MB perf.data (~132504 samples) ]
> [root@zoo acme]# perf report --stdio --branch-history
> # To display the perf.data header info, please use --header/--header-only options.
> #
> BFD: Dwarf Error: Offset (2585882475) greater than or equal to .debug_str size (44321517).
> BFD: Dwarf Error: Could not find abbrev number 11800.
> <BIG SNIP>
> BFD: Dwarf Error: Offset (83496016) greater than or equal to .debug_str size (44321517).
> BFD: Dwarf Error: Offset (48628447) greater than or equal to .debug_str size (44321517).
> (END)Segmentation fault (core dumped)
> [root@zoo acme]# 
> 
> Will investigate this later today/tomorrow, if nobody finds a fix in the meantime.

I cannot reproduce this.

For me it looks like you have some binary or debuginfo that your libbfd
doesn't like. --branch-history resolves all addresses as srcline, 
so it will actually walk all the line numbers.

Can you please find out which one it is? Probably can be seen
by just going up a few levels in gdb and dumping the event.

If you can find the address that explodes you can also try it directly with
addr2line. If that works it's some problem in the perf implementation.

It is likely that it would need to be fixed in libbfd.

To work around it we could turn off force resolving the srcline,
but that would make the output much less useful too unfortuantely...

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

Re: perf/branch-history branch build broken with NO_DEMANGLE=1 perf hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 11:52:44PM +0100, Andi Kleen escreveu:
> > [root@zoo acme]# perf record -a -g -b sleep 2s
> > [ perf record: Captured and wrote 3.033 MB perf.data (~132504 samples) ]
> > [root@zoo acme]# perf report --stdio --branch-history
> > # To display the perf.data header info, please use --header/--header-only options.
> > BFD: Dwarf Error: Offset (2585882475) greater than or equal to .debug_str size (44321517).
> > BFD: Dwarf Error: Could not find abbrev number 11800.
> > <BIG SNIP>
> > BFD: Dwarf Error: Offset (83496016) greater than or equal to .debug_str size (44321517).
> > BFD: Dwarf Error: Offset (48628447) greater than or equal to .debug_str size (44321517).
> > (END)Segmentation fault (core dumped)
> > [root@zoo acme]# 

> > Will investigate this later today/tomorrow, if nobody finds a fix in the meantime.
 
> I cannot reproduce this.
 
> For me it looks like you have some binary or debuginfo that your libbfd
> doesn't like. --branch-history resolves all addresses as srcline, 
> so it will actually walk all the line numbers.

 
> Can you please find out which one it is? Probably can be seen
> by just going up a few levels in gdb and dumping the event.

> If you can find the address that explodes you can also try it directly with
> addr2line. If that works it's some problem in the perf implementation.

Right, I'll try and figure this out, since you didn't manage to easily
reproduce this.
 
> It is likely that it would need to be fixed in libbfd.
> 
> To work around it we could turn off force resolving the srcline,
> but that would make the output much less useful too unfortuantely...

I'll try to find out if there is something that can flag a file as
"unsafe" to feed libbfd with, so that we can have a workaround for known
buggy libbfds, if that ends up being really the case.

- Arnaldo

Re: probe + report for following branch history. was Re: [PATCH 1/2] perf hists browser: Print overhead percent value for first-level callchain

[Namhyung Kim]

Hi Arnaldo,

On Mon, 24 Nov 2014 11:52:27 -0300, Arnaldo Carvalho de Melo wrote:
> But the absolute line numbers on 'perf probe -L' and the offsets from function
> start in 'report' look like low hanging fruits and a way to integrate further
> 'perf probe' with 'perf report', because both will look at the right file, keyed
> by the build-id, etc.

Okay, will do later :)

Thanks,
Namhyung

perf report --branch-history segfaul hists browser: Print overhead percent value for first-level callchain

[Arnaldo Carvalho de Melo]

Em Mon, Nov 24, 2014 at 11:52:44PM +0100, Andi Kleen escreveu:
> > [root@zoo acme]# perf record -a -g -b sleep 2s
> > [ perf record: Woken up 7 times to write data ]
> > [ perf record: Captured and wrote 3.033 MB perf.data (~132504 samples) ]
> > [root@zoo acme]# perf report --stdio --branch-history
> > # To display the perf.data header info, please use --header/--header-only options.
> > #
> > BFD: Dwarf Error: Offset (2585882475) greater than or equal to .debug_str size (44321517).
> > BFD: Dwarf Error: Could not find abbrev number 11800.
> > <BIG SNIP>
> > BFD: Dwarf Error: Offset (83496016) greater than or equal to .debug_str size (44321517).
> > BFD: Dwarf Error: Offset (48628447) greater than or equal to .debug_str size (44321517).
> > (END)Segmentation fault (core dumped)
> > [root@zoo acme]# 
> > 
> > Will investigate this later today/tomorrow, if nobody finds a fix in the meantime.
> 
> I cannot reproduce this.
> 
> For me it looks like you have some binary or debuginfo that your libbfd
> doesn't like. --branch-history resolves all addresses as srcline, 
> so it will actually walk all the line numbers.
> 
> Can you please find out which one it is? Probably can be seen
> by just going up a few levels in gdb and dumping the event.
> 
> If you can find the address that explodes you can also try it directly with
> addr2line. If that works it's some problem in the perf implementation.
> 
> It is likely that it would need to be fixed in libbfd.
> 
> To work around it we could turn off force resolving the srcline,
> but that would make the output much less useful too unfortuantely...

Yeah, you are right:

[acme@zoo linux]$ addr2line -e /usr/lib/debug/usr/lib64/firefox/libxul.so.debug 22fefe8
BFD: Dwarf Error: Offset (2585882475) greater than or equal to
.debug_str size (44321517).
BFD: Dwarf Error: Could not find abbrev number 11800.
BFD: Dwarf Error: Offset (493511937) greater than or equal to .debug_str
size (44321517).

[acme@zoo linux]$ file /usr/lib/debug/usr/lib64/firefox/libxul.so.debug
/usr/lib/debug/usr/lib64/firefox/libxul.so.debug: ELF 64-bit LSB shared
object, x86-64, version 1 (GNU/Linux), dynamically linked,
BuildID[sha1]=ab6f19f13352ca2fbf218d1ff9200ef8e29764b8, not stripped
[acme@zoo linux]$ 

[acme@zoo linux]$ rpm -qf /usr/lib/debug/usr/lib64/firefox/libxul.so.debug
firefox-debuginfo-33.1-2.fc20.x86_64

If I ignore just this one file, all works, I'll process your patch while
leaving a note in the changelog that this may trigger binutils bugs, and
will check if a later version of binutils has the same problem, etc.

- Arnaldo

Re: perf report --branch-history segfaul hists browser: Print overhead percent value for first-level callchain

[Andi Kleen]

Thanks for testing.

> Yeah, you are right:
> 
> [acme@zoo linux]$ addr2line -e /usr/lib/debug/usr/lib64/firefox/libxul.so.debug 22fefe8
> BFD: Dwarf Error: Offset (2585882475) greater than or equal to
> .debug_str size (44321517).
> BFD: Dwarf Error: Could not find abbrev number 11800.
> BFD: Dwarf Error: Offset (493511937) greater than or equal to .debug_str
> size (44321517).

But addr2line didn't crash? What happens when you run it under valgrind?

If yes, I can check what it does differently than get_srcline() to make
it recover better.

-Andi

[tip:perf/core] perf hists browser: Print overhead percent value for first-level callchain

[tip-bot for Namhyung Kim]

Commit-ID:  4087d11cd9455cd28da0795504451d1188633a0d
Gitweb:     http://git.kernel.org/tip/4087d11cd9455cd28da0795504451d1188633a0d
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Mon, 24 Nov 2014 17:13:26 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Mon, 24 Nov 2014 11:28:48 -0300

perf hists browser: Print overhead percent value for first-level callchain

Currently perf report on TUI doesn't print percent for first-level
callchain entry.

I guess it (wrongly) assumes that there's only a single callchain in the
first level.

This patch fixes it by handling the first level callchains same as
others - if it's not 100% it should print the percent value.

Also it'll affect other callchains in the other way around - if it's
100% (single callchain) it should not print the percentage.

Before:
  -   30.95%     6.84%  abc2     abc2              [.] a
     - a
        - 70.00% c
           - 100.00% apic_timer_interrupt
                smp_apic_timer_interrupt
                local_apic_timer_interrupt
                hrtimer_interrupt
                ...
        + 30.00% b
     + __libc_start_main

After:
  -   30.95%     6.84%  abc2     abc2              [.] a
     - 77.90% a
        - 70.00% c
           - apic_timer_interrupt
             smp_apic_timer_interrupt
             local_apic_timer_interrupt
             hrtimer_interrupt
             ...
        + 30.00% b
     + 22.10% __libc_start_main

Reported-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung.kim@lge.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1416816807-6495-1-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/ui/browsers/hists.c | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 12c17c5..8d22905 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -542,8 +542,11 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 	struct rb_node *node;
 	int first_row = row, offset = level * LEVEL_OFFSET_STEP;
 	u64 new_total;
+	bool need_percent;
 
 	node = rb_first(root);
+	need_percent = !!rb_next(node);
+
 	while (node) {
 		struct callchain_node *child = rb_entry(node, struct callchain_node, rb_node);
 		struct rb_node *next = rb_next(node);
@@ -560,7 +563,7 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 
 			if (first)
 				first = false;
-			else if (level > 1)
+			else if (need_percent)
 				extra_offset = LEVEL_OFFSET_STEP;
 
 			folded_sign = callchain_list__folded(chain);
@@ -573,7 +576,7 @@ static int hist_browser__show_callchain(struct hist_browser *browser,
 			str = callchain_list__sym_name(chain, bf, sizeof(bf),
 						       browser->show_dso);
 
-			if (was_first && level > 1) {
+			if (was_first && need_percent) {
 				double percent = cumul * 100.0 / total;
 
 				if (asprintf(&alloc_str, "%2.2f%% %s", percent, str) < 0)
@@ -790,6 +793,13 @@ static int hist_browser__show_entry(struct hist_browser *browser,
 			.is_current_entry = current_entry,
 		};
 
+		if (callchain_param.mode == CHAIN_GRAPH_REL) {
+			if (symbol_conf.cumulate_callchain)
+				total = entry->stat_acc->period;
+			else
+				total = entry->stat.period;
+		}
+
 		printed += hist_browser__show_callchain(browser,
 					&entry->sorted_chain, 1, row, total,
 					hist_browser__show_callchain_entry, &arg,

[tip:perf/core] perf tools: Collapse first level callchain entry if it has sibling

[tip-bot for Namhyung Kim]

Commit-ID:  a7444af69b2898bb9b3a847d3599e1fc98356ce5
Gitweb:     http://git.kernel.org/tip/a7444af69b2898bb9b3a847d3599e1fc98356ce5
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Mon, 24 Nov 2014 17:13:27 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Mon, 24 Nov 2014 11:34:33 -0300

perf tools: Collapse first level callchain entry if it has sibling

If first level callchain has more than single path like when -g caller
option is given, it should show only first one in the path and hide
others.  But it didn't do it properly and just hindered the output.

Before:
  -   80.33%    11.11%  abc2     abc2              [.] main
     + 86.18% main
       13.82% __libc_start_main
          main

After:
  -   80.33%    11.11%  abc2     abc2              [.] main
     + 86.18% main
     + 13.82% __libc_start_main

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung.kim@lge.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1416816807-6495-2-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/ui/browsers/hists.c | 11 ++++++++---
 1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 8d22905..502daff 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -227,10 +227,14 @@ static void callchain_node__init_have_children_rb_tree(struct callchain_node *no
 	}
 }
 
-static void callchain_node__init_have_children(struct callchain_node *node)
+static void callchain_node__init_have_children(struct callchain_node *node,
+					       bool has_sibling)
 {
 	struct callchain_list *chain;
 
+	chain = list_entry(node->val.next, struct callchain_list, list);
+	chain->ms.has_children = has_sibling;
+
 	if (!list_empty(&node->val)) {
 		chain = list_entry(node->val.prev, struct callchain_list, list);
 		chain->ms.has_children = !RB_EMPTY_ROOT(&node->rb_root);
@@ -241,11 +245,12 @@ static void callchain_node__init_have_children(struct callchain_node *node)
 
 static void callchain__init_have_children(struct rb_root *root)
 {
-	struct rb_node *nd;
+	struct rb_node *nd = rb_first(root);
+	bool has_sibling = nd && rb_next(nd);
 
 	for (nd = rb_first(root); nd; nd = rb_next(nd)) {
 		struct callchain_node *node = rb_entry(nd, struct callchain_node, rb_node);
-		callchain_node__init_have_children(node);
+		callchain_node__init_have_children(node, has_sibling);
 	}
 }