lkml.org 
[lkml]   [2009]   [Dec]   [14]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH 3/3] perf diff: Introduce tool to show performance difference
Em Mon, Dec 14, 2009 at 02:47:08PM -0800, Paul E. McKenney escreveu:
> On Mon, Dec 14, 2009 at 08:09:31PM -0200, Arnaldo Carvalho de Melo wrote:
> > From: Arnaldo Carvalho de Melo <acme@redhat.com>
> >
> > I guess it is enough to show some examples:
>
> Very cool!!!
>
> Some questions on the numbers below...

Lets go!

> > [root@doppio linux-2.6-tip]# rm -f perf.data*
> > [root@doppio linux-2.6-tip]# ls -la perf.data*
> > ls: cannot access perf.data*: No such file or directory
> > [root@doppio linux-2.6-tip]# perf record -f find / > /dev/null
> > [ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.062 MB perf.data (~2699 samples) ]
> > [root@doppio linux-2.6-tip]# ls -la perf.data*
> > -rw------- 1 root root 74440 2009-12-14 20:03 perf.data
> > [root@doppio linux-2.6-tip]# perf record -f find / > /dev/null
> > [ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.062 MB perf.data (~2692 samples) ]
> > [root@doppio linux-2.6-tip]# ls -la perf.data*
> > -rw------- 1 root root 74280 2009-12-14 20:03 perf.data
> > -rw------- 1 root root 74440 2009-12-14 20:03 perf.data.old
> > [root@doppio linux-2.6-tip]# perf diff | head -5
> > 1 -34994580 /lib64/libc-2.10.1.so _IO_vfprintf_internal
> > 2 -15307806 [kernel.kallsyms] __kmalloc
> > 3 +1 +3665941 /lib64/libc-2.10.1.so __GI_memmove
> > 4 +4 +23508995 /lib64/libc-2.10.1.so _int_malloc
> > 5 +7 +38538813 [kernel.kallsyms] __d_lookup
>
> The first column seems to be the sequence number. The second column is
> the change in position, in other words, __GI_memmove moved up one row?
> The third column looks like the change in profile counts.

Yeap, its something I wanted to have in this new baby, something I
followed closely for over a year while my football (or soccer, as some
region of the world calls it), i.e. what happened from the last round,
how many positions one entry moved up or down.

So, yes, __GI_memmove moved one row up, one way to double check that is
to:

perf record -i perf.data.old

in one xterm

then:

perf record

in another, and look at what happen when you flip those xterms

Yeap, its something I wanted to have in this new baby, something I
followed closely for over a year while my football (or soccer, as some
region of the world calls it), i.e. what happened from the last round,
how many positions one entry moved up or down.

So, yes, __GI_memmove moved one row up, one way to double check that is
to:

perf record -i perf.data.old

in one xterm

then:

perf record

in another, and look at what happen when you flip those xterms.

And if you want to see an html rendering of what I wanted to get coming
accross:

http://esporte.uol.com.br/futebol/campeonatos/brasileiro/2009/serie-a/classificacao.jhtm

> > [root@doppio linux-2.6-tip]# perf diff -p | head -5
> > 1 +1.00% /lib64/libc-2.10.1.so _IO_vfprintf_internal
> > 2 [kernel.kallsyms] __kmalloc
> > 3 +1 /lib64/libc-2.10.1.so __GI_memmove
> > 4 +4 /lib64/libc-2.10.1.so _int_malloc
> > 5 +7 -1.00% [kernel.kallsyms] __d_lookup
>
> The third column is percent of total execution time? Or percent change
> in profile ticks? My guess is the former.

counter percentage wrt the total number of hits for that particualr
session. The unit is whatever is specified in --event, i.e. the counter
specified, whichever it is.

> > [root@doppio linux-2.6-tip]# perf diff -v | head -5
> > 1 361449551 326454971 -34994580 /lib64/libc-2.10.1.so _IO_vfprintf_internal
> > 2 151009241 135701435 -15307806 [kernel.kallsyms] __kmalloc
> > 3 +1 101805328 105471269 +3665941 /lib64/libc-2.10.1.so __GI_memmove
> > 4 +4 78041440 101550435 +23508995 /lib64/libc-2.10.1.so _int_malloc
> > 5 +7 59536172 98074985 +38538813 [kernel.kallsyms] __d_lookup
> > [root@doppio linux-2.6-tip]# perf diff -vp | head -5
> > 1 9.00% 8.00% +1.00% /lib64/libc-2.10.1.so _IO_vfprintf_internal
> > 2 3.00% 3.00% [kernel.kallsyms] __kmalloc
> > 3 +1 2.00% 2.00% /lib64/libc-2.10.1.so __GI_memmove
> > 4 +4 2.00% 2.00% /lib64/libc-2.10.1.so _int_malloc
> > 5 +7 1.00% 2.00% -1.00% [kernel.kallsyms] __d_lookup
>
> If these examples are all using the same numbers, then the percentages
> must be of total execution time rather than percent change in the
> profiling ticks?

Its all using the same perf.data.old + perf.data files, so the numbers
are for the default -e metrics, which is PERF_COUNT_HW_CPU_CYCLES.

> > [root@doppio linux-2.6-tip]#
> >
> > This should be enough for diffs where the system is non volatile, i.e. when one
> > doesn't updates binaries.
> >
> > For volatile environments, stay tuned for the next perf tool feature: a buildid
> > cache populated by 'perf record', managed by 'perf buildid-cache' a-la ccache,
> > and used by all the report tools.
>
> For scalability studies, it would be very cool to have a ratio as well
> as a difference, but again, good stuff!!!

Point taken!

Please let me know about any other issue or suggestion you may come to!

- Arnaldo


\
 
 \ /
  Last update: 2009-12-15 00:33    [W:0.759 / U:0.204 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site