[PROBLEM] perf report is broken in latest linus git
From: Pekka Enberg
Date: Thu Aug 13 2009 - 05:28:38 EST
Hi all!
I don't know what to make out of this. I am profiling my userspace VM with perf
and something happened between 2.6.31-rc4 (which worked perfectly) and latest
Linus git. I am seeing completely different perf profiles and from what I can
tell, the userspace part isn't causing which makes me think it's a kernel
bug. See below for the perf reports.
Pekka
Linux 2.6.31-rc4 (both kernel and userspace):
[ Note: this makes the most sense to me knowing what the app does. ]
penberg@penberg-laptop:~/testing/jato$ perf record -f jato HelloWorldSwing
[ perf record: Captured and wrote 1.401 MB perf.data (~61218 samples) ]
penberg@penberg-laptop:~/testing/jato$ perf report --sort comm,dso,symbol
# Samples: 60421
#
# Overhead Command Shared Object Symbol
# ........ ....... ....................................... ......
#
69.86% jato /home/penberg/bin/jato [.] gc_map_init
2.06% jato /lib/tls/i686/cmov/libc-2.8.90.so [.] _int_malloc
1.95% jato /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI_strcmp
1.68% jato /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI___libc_malloc
1.61% jato [kernel] [k] get_page_from_freelist
1.01% jato /home/penberg/bin/jato [.] zalloc
0.97% jato /usr/lib/libzip.so.1.0.0 [.] _zip_get_name
0.85% jato /home/penberg/bin/jato [.] cafebabe_constant_info_utf8_compare
0.69% jato /usr/lib/libz.so.1.2.3.3 [.] 0x0000000000e445
0.59% jato /lib/tls/i686/cmov/libc-2.8.90.so [.] cfree
0.58% jato /home/penberg/bin/jato [.] analyze_liveness
0.56% jato /home/penberg/bin/jato [.] split_interval_at
0.56% jato /usr/lib/libfontconfig.so.1.3.0 [.] 0x0000000001127e
0.56% jato /home/penberg/bin/jato [.] allocate_registers
Latest Linus git kernel with -rc4 perf userspace:
penberg@penberg-laptop:~/testing/jato$ perf record -f jato HelloWorldSwing
[ perf record: Captured and wrote 1.402 MB perf.data (~61261 samples) ]
penberg@penberg-laptop:~/testing/jato$ perf report --sort comm,dso,symbol|head -30
# Samples: 60457
#
# Overhead Command Shared Object Symbol
# ........ ....... ....................................... ......
#
[ Note: the jato executable doesn't appear anywhere in the trace. I'm
pretty sure the libzip functions, for example, are from jato, not perf. ]
36.14% perf /home/penberg/bin/perf [.] dso__synthesize_plt_symbols
35.20% perf /home/penberg/bin/perf [.] dso__new
3.57% perf /home/penberg/bin/jato [.] 0x0000000000c910
2.10% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] _int_malloc
1.89% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI_strcmp
1.63% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI___libc_malloc
1.44% perf [kernel] [k] get_page_from_freelist
1.04% perf /home/penberg/bin/perf [.] dso__load_sym
0.94% perf /usr/lib/libzip.so.1.0.0 [.] _zip_get_name
0.60% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] cfree
0.52% perf /home/penberg/bin/perf [.] dso__load_kernel
0.46% perf /usr/lib/libzip.so.1.0.0 [.] _zip_name_locate
0.46% perf /usr/lib/libfontconfig.so.1.3.0 [.] 0x00000000016706
0.42% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] _int_free
0.40% perf [kernel] [k] kunmap_atomic
0.38% perf /home/penberg/bin/perf [.] cmd_stat
0.34% perf /home/penberg/bin/perf [.] quote_c_style_counted
0.33% perf /usr/lib/libz.so.1.2.3.3 [.] 0x0000000000ea89
0.32% perf /home/penberg/bin/perf [.] 0x000000000261ea
0.32% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] malloc_consolidate
0.30% perf /home/penberg/bin/perf [.] strbuf_grow
0.30% perf /home/penberg/bin/perf [.] store_aux
0.30% perf /home/penberg/bin/jato [.] zalloc
0.29% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI___libc_realloc
0.27% perf /home/penberg/bin/perf [.] strbuf_addf
Latest Linus git kernel and userspace:
[ perf record: Captured and wrote 1.348 MB perf.data (~58887 samples) ]
penberg@penberg-laptop:~/testing/jato$ perf record -f jato HelloWorldSwing
[ perf record: Captured and wrote 1.342 MB perf.data (~58623 samples) ]
penberg@penberg-laptop:~/testing/jato$ perf report | head -30
# Samples: 57821
#
# Overhead Command Shared Object Symbol
# ........ ....... ....................................... ......
#
72.88% perf /home/penberg/bin/perf [.] strbuf_readlink
6.53% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] 0x0000000014b8c0
3.31% perf /home/penberg/bin/jato [.] 0x0000000000c910
1.37% perf [kernel] [k] get_page_from_freelist
0.91% perf /usr/lib/libzip.so.1.0.0 [.] _zip_get_name
0.67% perf /home/penberg/bin/perf [.] strbuf_getline
0.59% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] __GI_strcmp
0.57% perf /usr/lib/libfontconfig.so.1.3.0 [.] 0x00000000019700
0.53% perf /usr/lib/libz.so.1.2.3.3 [.] 0x0000000000f0c5
0.50% perf /home/penberg/bin/perf [.] print_events
0.48% perf /home/penberg/bin/perf [.] quote_c_style_counted
0.47% perf /home/penberg/bin/perf [.] rb_erase
0.40% perf /home/penberg/bin/perf [.] strlist__load
0.40% perf /home/penberg/bin/perf [.] display_thread
0.40% perf /home/penberg/bin/perf [.] run_hook
0.34% perf [kernel] [k] kunmap_atomic
0.32% perf /home/penberg/bin/perf [.] strlist__parse_list_entry
0.31% perf /lib/tls/i686/cmov/libc-2.8.90.so [.] _int_malloc
0.30% perf /home/penberg/bin/perf [.] dso__load
0.28% perf /usr/lib/libzip.so.1.0.0 [.] _zip_name_locate
0.28% perf /home/penberg/bin/perf [.] cmd_stat
0.26% perf /home/penberg/bin/perf [.] run_command_v_opt
0.25% perf /home/penberg/bin/perf [.] strlist__parse_list
0.23% perf a7d8bb0a [.] 0x000000a7d8bb0a
0.21% perf /home/penberg/bin/jato [.] cafebabe_constant_info_utf8_compare
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/