| Summary: | perf report output is in reverse order | ||
|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | IBM Bug Proxy <bugproxy> |
| Component: | kernel | Assignee: | Kernel Maintainer List <kernel-maint> |
| Status: | CLOSED ERRATA | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
| Severity: | medium | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 16 | CC: | gansalmon, itamar, jkachuck, jonathan, kernel-maint, madhu.chinakonda, wgomerin |
| Target Milestone: | --- | Keywords: | Reopened |
| Target Release: | --- | ||
| Hardware: | ppc64 | ||
| OS: | All | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2012-02-29 18:53:39 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
------- Comment From ebmunson.com 2011-11-01 12:36 EDT------- I can't reproduce this with 3.1, odds are good this was fixed between rc9 and release. I used the same test as listed [root@tundro5 ~]# uname -r 3.1.0-autokern1 [root@tundro5 ~]# perf record -f -e cycles -c 100000 ~/memknobs ... [ perf record: Woken up 49 times to write data ] [ perf record: Captured and wrote 12.129 MB perf.data (~529927 samples) ] [root@tundro5 ~]# perf report -n --stdio # Events: 397K cycles # Overhead Samples Command Shared Object # ........ .......... ....... ................. ............................ 41.33% 164248 memknobs memknobs [.] touchit 21.84% 86798 memknobs [vdso] [.] 0xfff933b057c 17.96% 71385 memknobs memknobs [.] tv_to_double 10.55% 41914 memknobs memknobs [.] now 5.50% 21865 memknobs libc-2.12.so [.] __gettimeofday 1.93% 7670 memknobs memknobs [.] 00000011.plt_call.getti 0.25% 987 memknobs [unknown] [H] 0x8000000000ef09e8 0.07% 264 memknobs [unknown] [k] 0x314 0.03% 115 memknobs [kernel.kallsyms] [k] .__lock_acquire 0.03% 114 memknobs [kernel.kallsyms] [k] .mark_held_locks 0.02% 80 memknobs [kernel.kallsyms] [k] .trace_hardirqs_off_cal 0.02% 66 memknobs [kernel.kallsyms] [k] restore 0.02% 63 memknobs [kernel.kallsyms] [k] .lock_acquire 0.02% 62 memknobs [kernel.kallsyms] [k] .trace_hardirqs_on_call 0.01% 59 memknobs [kernel.kallsyms] [k] .mark_lock 0.01% 52 memknobs [kernel.kallsyms] [k] .arch_local_irq_restore 0.01% 51 memknobs [kernel.kallsyms] [k] .lock_release 0.01% 41 memknobs [kernel.kallsyms] [k] .sched_clock 0.01% 41 memknobs [kernel.kallsyms] [k] .debug_locks_off 0.01% 40 memknobs [kernel.kallsyms] [k] .down_read_trylock 0.01% 38 memknobs [kernel.kallsyms] [k] .get_page_from_freelist 0.01% 36 memknobs [kernel.kallsyms] [k] .__trace_hcall_exit 0.01% 36 memknobs [kernel.kallsyms] [k] .__trace_hcall_entry 0.01% 35 memknobs [kernel.kallsyms] [k] .do_wp_page 0.01% 35 memknobs [kernel.kallsyms] [k] .do_page_fault 0.01% 34 memknobs [kernel.kallsyms] [k] .lock_acquired 0.01% 32 memknobs [kernel.kallsyms] [k] .probe_hcall_entry 0.01% 30 memknobs [kernel.kallsyms] [k] .plpar_hcall 0.01% 28 memknobs [kernel.kallsyms] [k] .handle_mm_fault 0.01% 27 memknobs memknobs [.] run 0.01% 27 memknobs [kernel.kallsyms] [k] .probe_hcall_exit 0.01% 26 memknobs [kernel.kallsyms] [k] system_call_common 0.01% 24 memknobs [kernel.kallsyms] [k] .audit_syscall_entry 0.01% 24 memknobs [kernel.kallsyms] [k] .__inc_zone_state 0.01% 24 memknobs [kernel.kallsyms] [k] .do_raw_spin_trylock 0.01% 23 memknobs [kernel.kallsyms] [k] .account_system_vtime 0.01% 23 memknobs [kernel.kallsyms] [k] .alloc_pages_vma 0.01% 22 memknobs [kernel.kallsyms] [k] .hash_page 0.01% 22 memknobs [kernel.kallsyms] [k] .__alloc_pages_nodemask ... F16 primary is already on the 3.1 final kernel. The ppc builders need to get it built and integrated into a ppc repo/iso. This is still an issue with 3.1.5-6 for ppc64. I'd like to reopen it and request that we keep it open for tracking purposes until it's fixed for Power. I tested 3.1.5-6 on a POWER7 lpar (thanks Brent!). This doesn't show the problem you seem to have:
[jwboyer@coho ~]$ perf record -f -e cycles -c 100000 ~/memknobs
allocated 20 MB
will touch 20 MB on each pass, making 1000 passes
104857 bytes of the touched data will be different on each pass
allocating buffer (20971520 bytes)...done: 0xfff782d0000
run_duration: 60.000000 elapsed: 1.611710e-04
loop_duration: 1.000000
pass rate: 25397.51 MB/sec (2000.0 loops in 0.79 sec) avg: 25397.51 MB/s (0MB -> 0MB) 2.000000
pass rate: 26459.61 MB/sec (2000.0 loops in 0.76 sec) avg: 25928.56 MB/s (0MB -> 0MB) 4.000000
pass rate: 26383.38 MB/sec (2000.0 loops in 0.76 sec) avg: 26080.17 MB/s (0MB -> 0MB) 8.000000
pass rate: 26479.27 MB/sec (2000.0 loops in 0.76 sec) avg: 26179.94 MB/s (0MB -> 0MB) 16.000000
pass rate: 26092.29 MB/sec (2000.0 loops in 0.77 sec) avg: 26162.41 MB/s (0MB -> 0MB) 32.000000
pass rate: 26409.76 MB/sec (2000.0 loops in 0.76 sec) avg: 26203.63 MB/s (0MB -> 0MB) 64.000000
pass rate: 26292.68 MB/sec (2000.0 loops in 0.76 sec) avg: 26216.36 MB/s (0MB -> 0MB) 128.000000
pass rate: 26432.16 MB/sec (2000.0 loops in 0.76 sec) avg: 26243.33 MB/s (0MB -> 0MB) 256.000000
pass rate: 26670.51 MB/sec (2000.0 loops in 0.75 sec) avg: 26290.79 MB/s (0MB -> 0MB) 512.000000
pass rate: 26228.99 MB/sec (2000.0 loops in 0.76 sec) avg: 26284.62 MB/s (0MB -> 0MB) 1024.000000
pass rate: 25992.90 MB/sec (2000.0 loops in 0.77 sec) avg: 26258.10 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26525.70 MB/sec (2000.0 loops in 0.75 sec) avg: 26280.39 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26198.44 MB/sec (2000.0 loops in 0.76 sec) avg: 26274.09 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26641.16 MB/sec (2000.0 loops in 0.75 sec) avg: 26300.31 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26497.22 MB/sec (2000.0 loops in 0.75 sec) avg: 26313.44 MB/s (1MB -> 1MB) 1024.000000
pass rate: 25821.11 MB/sec (2000.0 loops in 0.77 sec) avg: 26282.67 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26423.25 MB/sec (2000.0 loops in 0.76 sec) avg: 26290.94 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26753.85 MB/sec (2000.0 loops in 0.75 sec) avg: 26316.65 MB/s (1MB -> 1MB) 1024.000000
pass rate: 25844.56 MB/sec (2000.0 loops in 0.77 sec) avg: 26291.81 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26017.45 MB/sec (2000.0 loops in 0.77 sec) avg: 26278.09 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26252.57 MB/sec (2000.0 loops in 0.76 sec) avg: 26276.88 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26303.09 MB/sec (2000.0 loops in 0.76 sec) avg: 26278.07 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26513.70 MB/sec (2000.0 loops in 0.75 sec) avg: 26288.31 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26814.47 MB/sec (2000.0 loops in 0.75 sec) avg: 26310.23 MB/s (2MB -> 2MB) 1024.000000
pass rate: 25805.49 MB/sec (2000.0 loops in 0.78 sec) avg: 26290.04 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26238.08 MB/sec (2000.0 loops in 0.76 sec) avg: 26288.04 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26301.12 MB/sec (2000.0 loops in 0.76 sec) avg: 26288.53 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26444.15 MB/sec (2000.0 loops in 0.76 sec) avg: 26294.09 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26420.18 MB/sec (2000.0 loops in 0.76 sec) avg: 26298.44 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26177.29 MB/sec (2000.0 loops in 0.76 sec) avg: 26294.40 MB/s (2MB -> 2MB) 1024.000000
pass rate: 25818.51 MB/sec (2000.0 loops in 0.77 sec) avg: 26279.05 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26681.89 MB/sec (2000.0 loops in 0.75 sec) avg: 26291.63 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26390.80 MB/sec (2000.0 loops in 0.76 sec) avg: 26294.64 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26550.83 MB/sec (2000.0 loops in 0.75 sec) avg: 26302.18 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26714.97 MB/sec (2000.0 loops in 0.75 sec) avg: 26313.97 MB/s (3MB -> 3MB) 1024.000000
pass rate: 27035.98 MB/sec (2000.0 loops in 0.74 sec) avg: 26334.03 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26268.23 MB/sec (2000.0 loops in 0.76 sec) avg: 26332.25 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26637.29 MB/sec (2000.0 loops in 0.75 sec) avg: 26340.28 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26520.38 MB/sec (2000.0 loops in 0.75 sec) avg: 26344.89 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26487.82 MB/sec (2000.0 loops in 0.76 sec) avg: 26348.47 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26544.31 MB/sec (2000.0 loops in 0.75 sec) avg: 26353.24 MB/s (4MB -> 4MB) 1024.000000
pass rate: 25943.16 MB/sec (2000.0 loops in 0.77 sec) avg: 26343.48 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26478.01 MB/sec (2000.0 loops in 0.76 sec) avg: 26346.61 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26799.92 MB/sec (2000.0 loops in 0.75 sec) avg: 26356.91 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26481.44 MB/sec (2000.0 loops in 0.76 sec) avg: 26359.68 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26037.06 MB/sec (2000.0 loops in 0.77 sec) avg: 26352.66 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26164.55 MB/sec (2000.0 loops in 0.76 sec) avg: 26348.66 MB/s (4MB -> 4MB) 1024.000000
pass rate: 25849.51 MB/sec (2000.0 loops in 0.77 sec) avg: 26338.26 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26147.35 MB/sec (2000.0 loops in 0.76 sec) avg: 26334.37 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26687.16 MB/sec (2000.0 loops in 0.75 sec) avg: 26341.42 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26432.51 MB/sec (2000.0 loops in 0.76 sec) avg: 26343.21 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26216.00 MB/sec (2000.0 loops in 0.76 sec) avg: 26340.76 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26242.24 MB/sec (2000.0 loops in 0.76 sec) avg: 26338.90 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26633.04 MB/sec (2000.0 loops in 0.75 sec) avg: 26344.35 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26391.01 MB/sec (2000.0 loops in 0.76 sec) avg: 26345.20 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26285.31 MB/sec (2000.0 loops in 0.76 sec) avg: 26344.13 MB/s (5MB -> 5MB) 1024.000000
pass rate: 25921.24 MB/sec (2000.0 loops in 0.77 sec) avg: 26336.71 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26053.47 MB/sec (2000.0 loops in 0.77 sec) avg: 26331.83 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26670.15 MB/sec (2000.0 loops in 0.75 sec) avg: 26337.56 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26217.27 MB/sec (2000.0 loops in 0.76 sec) avg: 26335.55 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26258.19 MB/sec (2000.0 loops in 0.76 sec) avg: 26334.29 MB/s (6MB -> 6MB) 1024.000000
run_duration 60.000000 elapsed
[ perf record: Woken up 197 times to write data ]
[ perf record: Captured and wrote 49.161 MB perf.data (~2147856 samples) ]
[jwboyer@coho ~]$ perf report -n --stdio
# ========
# captured on: Wed Feb 29 18:38:51 2012
# hostname : coho.fedora.osuosl.org
# os release : 3.1.5-6.fc16.ppc64
# perf version : 3.2.6-3.fc16.ppc64
# arch : ppc64
# nrcpus online : 16
# nrcpus avail : 8
# cpudesc : POWER7 (architected), altivec supported
# cpuid : 63,513
# total memory : 8333184 kB
# cmdline : /usr/bin/perf record -f -e cycles -c 100000 /home/jwboyer/memknobs
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, e
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# ========
#
# Events: 1M cycles
#
# Overhead Samples Command Shared Object
# ........ .......... ........ ................. ............................
#
113.35% 29424 memknobs libc-2.14.90.so [.] __gettimeofday
100.27% 510317 memknobs memknobs [.] tv_to_double
57.64% 7384 memknobs memknobs [.] 00000011.plt_call.gettim
54.75% 778569 memknobs memknobs [.] touchit
30.42% 227293 memknobs [vdso] [.] 0xfff796e0590
15.63% 54711 memknobs memknobs [.] now
14.32% 614 memknobs [unknown] [H] 0x55b3bc
6.86% 294 memknobs [kernel.kallsyms] [k] .scheduler_tick
3.57% 153 memknobs [kernel.kallsyms] [k] .perf_event_task_tick
3.34% 143 memknobs [kernel.kallsyms] [.] restore
3.31% 142 memknobs [unknown] [k] 0x80b2aca6c0
2.08% 89 memknobs memknobs [.] run
1.98% 85 memknobs [kernel.kallsyms] [k] .audit_syscall_exit
1.80% 77 memknobs libc-2.14.90.so [.] memcpy
1.61% 69 memknobs [kernel.kallsyms] [k] .do_sigaction
1.59% 68 memknobs [kernel.kallsyms] [k] system_call_common
1.45% 62 memknobs [kernel.kallsyms] [k] .clear_user_page
1.38% 59 memknobs libc-2.14.90.so [.] memset
1.31% 56 memknobs libc-2.14.90.so [.] __GI___libc_sigaction
1.19% 51 memknobs libc-2.14.90.so [.] __bsd_signal
1.17% 50 memknobs [kernel.kallsyms] [k] .SyS_rt_sigaction
1.12% 48 memknobs [kernel.kallsyms] [k] ._raw_spin_lock_irq
1.00% 43 memknobs [kernel.kallsyms] [k] .do_syscall_trace_enter
1.00% 43 memknobs [kernel.kallsyms] [k] .arch_local_irq_restore
0.96% 41 memknobs [kernel.kallsyms] [k] .__copy_tofrom_user
0.82% 35 memknobs [kernel.kallsyms] [k] syscall_exit
0.75% 32 memknobs [kernel.kallsyms] [k] .current_kernel_time
0.72% 31 memknobs [kernel.kallsyms] [k] syscall_exit_work
0.70% 30 memknobs libc-2.14.90.so [.] __GI___sigaction
0.68% 29 memknobs [kernel.kallsyms] [k] .account_system_vtime
0.63% 27 memknobs [kernel.kallsyms] [k] .ret_from_except_lite
0.63% 27 memknobs [kernel.kallsyms] [k] .copy_from_user
0.63% 27 memknobs [kernel.kallsyms] [k] .kfree
0.63% 27 memknobs [kernel.kallsyms] [k] ._cond_resched
0.58% 25 memknobs [kernel.kallsyms] [k] .run_timer_softirq
0.58% 25 memknobs [kernel.kallsyms] [k] .audit_syscall_entry
0.54% 23 memknobs [kernel.kallsyms] [k] .do_syscall_trace_leave
0.54% 23 memknobs [kernel.kallsyms] [k] .path_put
0.51% 22 memknobs [kernel.kallsyms] [k] .dput
0.47% 20 memknobs [kernel.kallsyms] [k] .run_posix_cpu_timers
0.44% 19 memknobs [kernel.kallsyms] [k] .perf_ctx_unlock
0.44% 19 memknobs [kernel.kallsyms] [k] ._raw_spin_lock
0.40% 17 memknobs [kernel.kallsyms] [k] .cpuacct_update_stats
0.35% 15 memknobs [kernel.kallsyms] [k] system_call
0.35% 15 memknobs [kernel.kallsyms] [k] ._raw_spin_lock_irqsave
0.28% 12 memknobs [kernel.kallsyms] [k] .hrtimer_interrupt
0.28% 12 memknobs [kernel.kallsyms] [k] .mntput
0.23% 10 memknobs [kernel.kallsyms] [k] .acct_update_integrals
0.21% 9 memknobs [kernel.kallsyms] [k] .flush_dcache_page
0.21% 9 memknobs [kernel.kallsyms] [k] .copy_to_user
0.19% 8 memknobs [kernel.kallsyms] [k] .jiffies_to_timeval
0.16% 7 memknobs [kernel.kallsyms] [k] .save_nvgprs
0.16% 7 memknobs [kernel.kallsyms] [k] .do_softirq
0.16% 7 memknobs [kernel.kallsyms] [k] .__do_softirq
0.14% 6 memknobs libc-2.14.90.so [.] vfprintf@@GLIBC_2.4
0.14% 6 memknobs [kernel.kallsyms] [k] .tick_sched_timer
0.14% 6 memknobs [kernel.kallsyms] [k] .unroll_tree_refs
0.14% 6 memknobs [kernel.kallsyms] [k] .find_next_bit
0.12% 5 memknobs [kernel.kallsyms] [k] syscall_dotrace
0.12% 5 memknobs [kernel.kallsyms] [k] .timebase_read
0.12% 5 memknobs [kernel.kallsyms] [k] .decrementer_set_next_ev
0.12% 5 memknobs [kernel.kallsyms] [k] .irq_exit
0.12% 5 memknobs [kernel.kallsyms] [k] .__run_hrtimer
0.12% 5 memknobs [kernel.kallsyms] [k] .ktime_get
0.09% 4 memknobs [kernel.kallsyms] [k] system_call_entry
0.09% 4 memknobs [kernel.kallsyms] [k] .timer_interrupt
0.09% 4 memknobs [kernel.kallsyms] [k] .idle_cpu
0.09% 4 memknobs [kernel.kallsyms] [k] .raise_softirq
0.09% 4 memknobs [kernel.kallsyms] [k] .force_qs_rnp
0.09% 4 memknobs [kernel.kallsyms] [k] .alloc_pages_vma
0.09% 4 memknobs [kernel.kallsyms] [k] .__percpu_counter_add
0.09% 4 memknobs [ehea] [k] .ehea_poll
0.07% 3 memknobs libc-2.14.90.so [.] __mpn_divrem
0.07% 3 memknobs libc-2.14.90.so [.] __printf_fp@@GLIBC_2.4
0.07% 3 memknobs libc-2.14.90.so [.] _IO_file_xsputn@@GLIBC_2
0.07% 3 memknobs [kernel.kallsyms] [k] .ret_from_except
0.07% 3 memknobs [kernel.kallsyms] [k] .copy_page
0.07% 3 memknobs [kernel.kallsyms] [k] .memset
0.07% 3 memknobs [kernel.kallsyms] [k] .account_system_time
0.07% 3 memknobs [kernel.kallsyms] [k] .__local_bh_enable
0.07% 3 memknobs [kernel.kallsyms] [k] .enqueue_hrtimer
0.07% 3 memknobs [kernel.kallsyms] [k] .clockevents_program_eve
0.07% 3 memknobs [kernel.kallsyms] [k] .tick_dev_program_event
0.07% 3 memknobs [kernel.kallsyms] [k] .__rcu_process_callbacks
0.07% 3 memknobs [kernel.kallsyms] [k] .rcu_enter_nohz
0.07% 3 memknobs [kernel.kallsyms] [.] .__perf_event_header__in
0.07% 3 memknobs [kernel.kallsyms] [k] .radix_tree_lookup_eleme
0.07% 3 memknobs [kernel.kallsyms] [k] .timerqueue_add
0.07% 3 memknobs [kernel.kallsyms] [k] .__list_add
0.07% 3 memknobs [kernel.kallsyms] [k] ._raw_spin_unlock_irqres
0.05% 2 memknobs memknobs [.] elapsed
0.05% 2 memknobs libc-2.14.90.so [.] __mpn_mul_1
0.05% 2 memknobs ld-2.14.90.so [.] _dl_relocate_object
0.05% 2 memknobs [kernel.kallsyms] [k] .hash_preload
0.05% 2 memknobs [kernel.kallsyms] [k] .ttwu_stat
0.05% 2 memknobs [kernel.kallsyms] [k] .update_curr
0.05% 2 memknobs [kernel.kallsyms] [k] .update_shares
0.05% 2 memknobs [kernel.kallsyms] [k] .idle_task
0.05% 2 memknobs [kernel.kallsyms] [k] .hrtimer_forward
0.05% 2 memknobs [kernel.kallsyms] [k] .__hrtimer_start_range_n
0.05% 2 memknobs [kernel.kallsyms] [k] .sched_clock_cpu
0.05% 2 memknobs [kernel.kallsyms] [k] .dyntick_save_progress_c
0.05% 2 memknobs [kernel.kallsyms] [k] .rcu_start_gp
0.05% 2 memknobs [kernel.kallsyms] [k] .rcu_bh_qs
0.05% 2 memknobs [kernel.kallsyms] [k] .__perf_event_task_sched
0.05% 2 memknobs [kernel.kallsyms] [.] .perf_prepare_sample
0.05% 2 memknobs [kernel.kallsyms] [k] .get_pageblock_flags_gro
0.05% 2 memknobs [kernel.kallsyms] [k] .do_wp_page
0.05% 2 memknobs [kernel.kallsyms] [k] .__mem_cgroup_uncharge_c
0.05% 2 memknobs [kernel.kallsyms] [k] .link_path_walk
0.05% 2 memknobs [kernel.kallsyms] [k] .avtab_search_node
0.05% 2 memknobs [kernel.kallsyms] [k] .blk_finish_request
0.05% 2 memknobs [kernel.kallsyms] [k] .cpumask_next_and
0.05% 2 memknobs [kernel.kallsyms] [k] .rb_insert_color
0.05% 2 memknobs [kernel.kallsyms] [k] .pty_write
0.05% 2 memknobs [kernel.kallsyms] [k] .__netif_receive_skb
0.05% 2 memknobs [kernel.kallsyms] [k] .tcp_v4_do_rcv
0.05% 2 memknobs [kernel.kallsyms] [k] .ipt_do_table
0.05% 2 memknobs [kernel.kallsyms] [k] .__schedule
0.05% 2 memknobs [ibmvscsic] [k] .ibmvscsi_handle_crq
0.05% 2 memknobs [ehea] [k] .ehea_proc_cqes.constpro
0.05% 2 memknobs [unknown] [.] 0x15eeac4
0.02% 1 memknobs memknobs [.] 00000011.plt_call.printf
0.02% 1 memknobs memknobs [.] 00000011.plt_call.usleep
0.02% 1 memknobs memknobs [.] __glink_PLTresolve
0.02% 1 memknobs libc-2.14.90.so [.] __mpn_extract_double
0.02% 1 memknobs libc-2.14.90.so [.] hack_digit.13208
0.02% 1 memknobs libc-2.14.90.so [.] _IO_old_init
0.02% 1 memknobs libc-2.14.90.so [.] __strchrnul
0.02% 1 memknobs libc-2.14.90.so [.] usleep
0.02% 1 memknobs libc-2.14.90.so [.] _dl_addr
0.02% 1 memknobs [kernel.kallsyms] [k] decrementer_common
0.02% 1 memknobs [kernel.kallsyms] [k] data_access_common
0.02% 1 memknobs [kernel.kallsyms] [k] .slb_miss_realmode
0.02% 1 memknobs [kernel.kallsyms] [k] hardware_interrupt_commo
0.02% 1 memknobs [kernel.kallsyms] [k] fp_unavailable_common
0.02% 1 memknobs [kernel.kallsyms] [k] do_work
0.02% 1 memknobs [kernel.kallsyms] [k] .load_up_fpu
0.02% 1 memknobs [kernel.kallsyms] [k] .call_do_softirq
0.02% 1 memknobs [kernel.kallsyms] [k] .arch_send_call_function
0.02% 1 memknobs [kernel.kallsyms] [k] .update_mmu_cache
0.02% 1 memknobs [kernel.kallsyms] [k] .hash_page
0.02% 1 memknobs [kernel.kallsyms] [k] .slb_miss_kernel_load_vm
0.02% 1 memknobs [kernel.kallsyms] [k] .slice_mask_for_size
0.02% 1 memknobs [kernel.kallsyms] [k] .find_linux_pte_or_hugep
0.02% 1 memknobs [kernel.kallsyms] [k] .__clear_user
0.02% 1 memknobs [kernel.kallsyms] [k] .__spin_yield
0.02% 1 memknobs [kernel.kallsyms] [k] .icp_hv_get_irq
0.02% 1 memknobs [kernel.kallsyms] [k] .pSeries_lpar_hpte_inval
0.02% 1 memknobs [kernel.kallsyms] [k] .plpar_hcall_norets
0.02% 1 memknobs [kernel.kallsyms] [k] .plpar_hcall
0.02% 1 memknobs [kernel.kallsyms] [k] .__wake_up_common
0.02% 1 memknobs [kernel.kallsyms] [k] .calc_delta_mine
0.02% 1 memknobs [kernel.kallsyms] [k] .check_preempt_wakeup
0.02% 1 memknobs [kernel.kallsyms] [k] .account_entity_dequeue
0.02% 1 memknobs [kernel.kallsyms] [k] .account_entity_enqueue
0.02% 1 memknobs [kernel.kallsyms] [k] .select_task_rq_fair
0.02% 1 memknobs [kernel.kallsyms] [k] .enqueue_task_fair
0.02% 1 memknobs [kernel.kallsyms] [k] .dequeue_task_fair
0.02% 1 memknobs [kernel.kallsyms] [k] .deactivate_task
0.02% 1 memknobs [kernel.kallsyms] [k] .try_to_wake_up
0.02% 1 memknobs [kernel.kallsyms] [k] .account_steal_time
0.02% 1 memknobs [kernel.kallsyms] [k] .find_busiest_group
0.02% 1 memknobs [kernel.kallsyms] [k] .load_balance
0.02% 1 memknobs [kernel.kallsyms] [k] .rebalance_domains
0.02% 1 memknobs [kernel.kallsyms] [k] .internal_add_timer
0.02% 1 memknobs [kernel.kallsyms] [k] .mod_timer
0.02% 1 memknobs [kernel.kallsyms] [k] .update_process_times
0.02% 1 memknobs [kernel.kallsyms] [k] .get_cwq
0.02% 1 memknobs [kernel.kallsyms] [k] .add_wait_queue
0.02% 1 memknobs [kernel.kallsyms] [k] .hrtimer_try_to_cancel
0.02% 1 memknobs [kernel.kallsyms] [k] .hrtimer_run_pending
0.02% 1 memknobs [kernel.kallsyms] [k] .hrtimer_nanosleep
0.02% 1 memknobs [kernel.kallsyms] [k] .down_read_trylock
0.02% 1 memknobs [kernel.kallsyms] [k] .up_read
0.02% 1 memknobs [kernel.kallsyms] [.] .local_clock
0.02% 1 memknobs [kernel.kallsyms] [k] .profile_tick
0.02% 1 memknobs [kernel.kallsyms] [k] .stop_one_cpu_nowait
0.02% 1 memknobs [kernel.kallsyms] [k] .force_quiescent_state
0.02% 1 memknobs [kernel.kallsyms] [k] .rcu_process_callbacks
0.02% 1 memknobs [kernel.kallsyms] [k] .rcu_irq_exit
0.02% 1 memknobs [kernel.kallsyms] [k] .ctx_sched_out
0.02% 1 memknobs [kernel.kallsyms] [k] .____pagevec_lru_add_fn
0.02% 1 memknobs [kernel.kallsyms] [k] .__lru_cache_add
0.02% 1 memknobs [kernel.kallsyms] [k] .find_vma
0.02% 1 memknobs [kernel.kallsyms] [k] .__remove_shared_vm_stru
0.02% 1 memknobs [kernel.kallsyms] [k] .unlink_anon_vmas
0.02% 1 memknobs [kernel.kallsyms] [k] .policy_zonelist
0.02% 1 memknobs [kernel.kallsyms] [k] .kmem_cache_free
0.02% 1 memknobs [kernel.kallsyms] [k] .__kmalloc
0.02% 1 memknobs [kernel.kallsyms] [k] .kmem_cache_alloc_node
0.02% 1 memknobs [kernel.kallsyms] [k] .kmem_cache_alloc_trace
0.02% 1 memknobs [kernel.kallsyms] [k] .__kmalloc_node_track_ca
0.02% 1 memknobs [kernel.kallsyms] [k] .__mem_cgroup_commit_cha
0.02% 1 memknobs [kernel.kallsyms] [k] .mem_cgroup_add_lru_list
0.02% 1 memknobs [kernel.kallsyms] [k] .mem_cgroup_newpage_char
0.02% 1 memknobs [kernel.kallsyms] [k] .rw_verify_area
0.02% 1 memknobs [kernel.kallsyms] [k] .file_free_rcu
0.02% 1 memknobs [kernel.kallsyms] [k] .generic_permission
0.02% 1 memknobs [kernel.kallsyms] [k] .path_openat
0.02% 1 memknobs [kernel.kallsyms] [k] .__d_lookup_rcu
0.02% 1 memknobs [kernel.kallsyms] [k] .bio_put
0.02% 1 memknobs [kernel.kallsyms] [k] .selinux_inode_permissio
0.02% 1 memknobs [kernel.kallsyms] [k] .ebitmap_get_bit
0.02% 1 memknobs [kernel.kallsyms] [k] .elv_put_request
0.02% 1 memknobs [kernel.kallsyms] [k] .elv_completed_request
0.02% 1 memknobs [kernel.kallsyms] [k] .blk_run_queue
0.02% 1 memknobs [kernel.kallsyms] [k] .blk_end_bidi_request
0.02% 1 memknobs [kernel.kallsyms] [k] .cfq_close_cooperator
0.02% 1 memknobs [kernel.kallsyms] [k] .rb_erase
0.02% 1 memknobs [kernel.kallsyms] [k] .__list_del_entry
0.02% 1 memknobs [kernel.kallsyms] [k] .tty_write_lock
0.02% 1 memknobs [kernel.kallsyms] [k] .do_output_char
0.02% 1 memknobs [kernel.kallsyms] [k] .process_output
0.02% 1 memknobs [kernel.kallsyms] [k] .tty_write_room
0.02% 1 memknobs [kernel.kallsyms] [k] .tty_insert_flip_string_
0.02% 1 memknobs [kernel.kallsyms] [k] .account
0.02% 1 memknobs [kernel.kallsyms] [k] .scsi_run_queue
0.02% 1 memknobs [kernel.kallsyms] [k] .scsi_io_completion
0.02% 1 memknobs [kernel.kallsyms] [k] .scsi_dma_unmap
0.02% 1 memknobs [kernel.kallsyms] [k] .dec_pending
0.02% 1 memknobs [kernel.kallsyms] [k] .__sk_mem_reclaim
0.02% 1 memknobs [kernel.kallsyms] [k] .netif_receive_skb
0.02% 1 memknobs [kernel.kallsyms] [k] .ip_route_input_common
0.02% 1 memknobs [kernel.kallsyms] [k] .ip_local_deliver_finish
0.02% 1 memknobs [kernel.kallsyms] [k] .ip_local_deliver
0.02% 1 memknobs [kernel.kallsyms] [k] .ip_rcv
0.02% 1 memknobs [kernel.kallsyms] [k] .__udp4_lib_rcv
0.02% 1 memknobs [kernel.kallsyms] [k] .bictcp_acked
0.02% 1 memknobs [kernel.kallsyms] [k] .schedule
0.02% 1 memknobs [kernel.kallsyms] [k] .down_read
0.02% 1 memknobs [kernel.kallsyms] [k] .do_page_fault
0.02% 1 memknobs [kernel.kallsyms] [k] .__slab_free
0.02% 1 memknobs [ibmvscsic] [k] .ibmvscsi_module_exit
0.02% 1 memknobs [ehea] [k] .ehea_proc_rwqes
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
[jwboyer@coho ~]$ uname -a
Linux coho.fedora.osuosl.org 3.1.5-6.fc16.ppc64 #1 SMP Tue Dec 20 21:24:05 UTC 2011 ppc64 ppc64 ppc64 GNU/Linux
[jwboyer@coho ~]$
However, that 113% looks slightly fishy. It might have been because I was using a newer perf than the kernel version running. So I updated the kernel to the latest in Fedora 16 updates (3.2.6-3) and it seems to work just fine:
[jwboyer@coho ~]$ perf record -f -e cycles -c 100000 ~/memknobs
allocated 20 MB
will touch 20 MB on each pass, making 1000 passes
104857 bytes of the touched data will be different on each pass
allocating buffer (20971520 bytes)...done: 0xfff97e50000
run_duration: 60.000000 elapsed: 1.330376e-04
loop_duration: 1.000000
pass rate: 25287.77 MB/sec (2000.0 loops in 0.79 sec) avg: 25287.77 MB/s (0MB -> 0MB) 2.000000
pass rate: 26523.47 MB/sec (2000.0 loops in 0.75 sec) avg: 25905.62 MB/s (0MB -> 0MB) 4.000000
pass rate: 26356.61 MB/sec (2000.0 loops in 0.76 sec) avg: 26055.95 MB/s (0MB -> 0MB) 8.000000
pass rate: 25840.19 MB/sec (2000.0 loops in 0.77 sec) avg: 26002.01 MB/s (0MB -> 0MB) 16.000000
pass rate: 26305.90 MB/sec (2000.0 loops in 0.76 sec) avg: 26062.79 MB/s (0MB -> 0MB) 32.000000
pass rate: 26248.75 MB/sec (2000.0 loops in 0.76 sec) avg: 26093.78 MB/s (0MB -> 0MB) 64.000000
pass rate: 26509.09 MB/sec (2000.0 loops in 0.75 sec) avg: 26153.11 MB/s (0MB -> 0MB) 128.000000
pass rate: 26354.21 MB/sec (2000.0 loops in 0.76 sec) avg: 26178.25 MB/s (0MB -> 0MB) 256.000000
pass rate: 26253.89 MB/sec (2000.0 loops in 0.76 sec) avg: 26186.65 MB/s (0MB -> 0MB) 512.000000
pass rate: 26335.34 MB/sec (2000.0 loops in 0.76 sec) avg: 26201.52 MB/s (0MB -> 0MB) 1024.000000
pass rate: 25991.68 MB/sec (2000.0 loops in 0.77 sec) avg: 26182.45 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26416.41 MB/sec (2000.0 loops in 0.76 sec) avg: 26201.94 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26647.34 MB/sec (2000.0 loops in 0.75 sec) avg: 26236.20 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26330.76 MB/sec (2000.0 loops in 0.76 sec) avg: 26242.96 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26323.97 MB/sec (2000.0 loops in 0.76 sec) avg: 26248.36 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26277.82 MB/sec (2000.0 loops in 0.76 sec) avg: 26250.20 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26180.75 MB/sec (2000.0 loops in 0.76 sec) avg: 26246.11 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26337.62 MB/sec (2000.0 loops in 0.76 sec) avg: 26251.20 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26613.54 MB/sec (2000.0 loops in 0.75 sec) avg: 26270.27 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26359.53 MB/sec (2000.0 loops in 0.76 sec) avg: 26274.73 MB/s (1MB -> 1MB) 1024.000000
pass rate: 26274.75 MB/sec (2000.0 loops in 0.76 sec) avg: 26274.73 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26363.28 MB/sec (2000.0 loops in 0.76 sec) avg: 26278.76 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26667.28 MB/sec (2000.0 loops in 0.75 sec) avg: 26295.65 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26441.21 MB/sec (2000.0 loops in 0.76 sec) avg: 26301.71 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26901.02 MB/sec (2000.0 loops in 0.74 sec) avg: 26325.69 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26147.55 MB/sec (2000.0 loops in 0.76 sec) avg: 26318.84 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26388.15 MB/sec (2000.0 loops in 0.76 sec) avg: 26321.40 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26712.08 MB/sec (2000.0 loops in 0.75 sec) avg: 26335.36 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26329.20 MB/sec (2000.0 loops in 0.76 sec) avg: 26335.14 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26210.12 MB/sec (2000.0 loops in 0.76 sec) avg: 26330.98 MB/s (2MB -> 2MB) 1024.000000
pass rate: 26201.13 MB/sec (2000.0 loops in 0.76 sec) avg: 26326.79 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26529.84 MB/sec (2000.0 loops in 0.75 sec) avg: 26333.13 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26157.91 MB/sec (2000.0 loops in 0.76 sec) avg: 26327.82 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26228.51 MB/sec (2000.0 loops in 0.76 sec) avg: 26324.90 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26078.85 MB/sec (2000.0 loops in 0.77 sec) avg: 26317.87 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26160.07 MB/sec (2000.0 loops in 0.76 sec) avg: 26313.49 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26515.68 MB/sec (2000.0 loops in 0.75 sec) avg: 26318.95 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26285.42 MB/sec (2000.0 loops in 0.76 sec) avg: 26318.07 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26341.43 MB/sec (2000.0 loops in 0.76 sec) avg: 26318.67 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26323.41 MB/sec (2000.0 loops in 0.76 sec) avg: 26318.79 MB/s (3MB -> 3MB) 1024.000000
pass rate: 26268.03 MB/sec (2000.0 loops in 0.76 sec) avg: 26317.55 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26615.95 MB/sec (2000.0 loops in 0.75 sec) avg: 26324.65 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26269.23 MB/sec (2000.0 loops in 0.76 sec) avg: 26323.37 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26397.38 MB/sec (2000.0 loops in 0.76 sec) avg: 26325.05 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26339.56 MB/sec (2000.0 loops in 0.76 sec) avg: 26325.37 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26299.80 MB/sec (2000.0 loops in 0.76 sec) avg: 26324.81 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26574.16 MB/sec (2000.0 loops in 0.75 sec) avg: 26330.12 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26089.91 MB/sec (2000.0 loops in 0.77 sec) avg: 26325.12 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26244.10 MB/sec (2000.0 loops in 0.76 sec) avg: 26323.46 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26039.09 MB/sec (2000.0 loops in 0.77 sec) avg: 26317.77 MB/s (4MB -> 4MB) 1024.000000
pass rate: 26022.63 MB/sec (2000.0 loops in 0.77 sec) avg: 26311.99 MB/s (5MB -> 5MB) 1024.000000
pass rate: 25843.33 MB/sec (2000.0 loops in 0.77 sec) avg: 26302.97 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26119.48 MB/sec (2000.0 loops in 0.77 sec) avg: 26299.51 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26242.96 MB/sec (2000.0 loops in 0.76 sec) avg: 26298.46 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26195.09 MB/sec (2000.0 loops in 0.76 sec) avg: 26296.59 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26047.40 MB/sec (2000.0 loops in 0.77 sec) avg: 26292.14 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26190.28 MB/sec (2000.0 loops in 0.76 sec) avg: 26290.35 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26091.64 MB/sec (2000.0 loops in 0.77 sec) avg: 26286.92 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26430.66 MB/sec (2000.0 loops in 0.76 sec) avg: 26289.36 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26788.53 MB/sec (2000.0 loops in 0.75 sec) avg: 26297.68 MB/s (5MB -> 5MB) 1024.000000
pass rate: 26626.98 MB/sec (2000.0 loops in 0.75 sec) avg: 26303.08 MB/s (6MB -> 6MB) 1024.000000
run_duration 60.000000 elapsed
[ perf record: Woken up 182 times to write data ]
[ perf record: Captured and wrote 45.395 MB perf.data (~1983337 samples) ]
[jwboyer@coho ~]$ perf report -n --stdio
# ========
# captured on: Wed Feb 29 18:50:28 2012
# hostname : coho.fedora.osuosl.org
# os release : 3.2.6-3.fc16.ppc64
# perf version : 3.2.6-3.fc16.ppc64
# arch : ppc64
# nrcpus online : 16
# nrcpus avail : 8
# cpudesc : POWER7 (architected), altivec supported
# cpuid : 63,513
# total memory : 8333440 kB
# cmdline : /usr/bin/perf record -f -e cycles -c 100000 /home/jwboyer/memknobs
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, e
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# ========
#
# Events: 1M cycles
#
# Overhead Samples Command Shared Object
# ........ .......... ........ ................. ............................
#
48.30% 718426 memknobs memknobs [.] touchit
31.60% 469986 memknobs memknobs [.] tv_to_double
14.41% 214288 memknobs [vdso] [.] 0xfff99260490
3.26% 48418 memknobs memknobs [.] now
1.80% 26759 memknobs libc-2.14.90.so [.] __gettimeofday
0.47% 7056 memknobs memknobs [.] 00000011.plt_call.gettim
0.03% 457 memknobs [unknown] [H] 0x523534
0.02% 258 memknobs [kernel.kallsyms] [k] .scheduler_tick
0.01% 139 memknobs [kernel.kallsyms] [.] restore
0.01% 126 memknobs [unknown] [k] 0x34c
0.01% 84 memknobs [kernel.kallsyms] [k] .audit_syscall_exit
0.01% 77 memknobs [kernel.kallsyms] [k] system_call_common
0.00% 74 memknobs memknobs [.] run
0.00% 62 memknobs [kernel.kallsyms] [k] .audit_syscall_entry
0.00% 61 memknobs [kernel.kallsyms] [k] .clear_user_page
0.00% 58 memknobs libc-2.14.90.so [.] memcpy
0.00% 52 memknobs [kernel.kallsyms] [k] .current_kernel_time
0.00% 51 memknobs [kernel.kallsyms] [k] ._raw_spin_lock_irq
0.00% 43 memknobs libc-2.14.90.so [.] __bsd_signal
0.00% 43 memknobs libc-2.14.90.so [.] memset
0.00% 40 memknobs [kernel.kallsyms] [k] .dput
0.00% 34 memknobs libc-2.14.90.so [.] __GI___libc_sigaction
0.00% 34 memknobs [kernel.kallsyms] [k] syscall_exit_work
0.00% 34 memknobs [kernel.kallsyms] [k] .do_sigaction
0.00% 31 memknobs [kernel.kallsyms] [k] .perf_event_task_tick
0.00% 30 memknobs [kernel.kallsyms] [k] .unroll_tree_refs
0.00% 27 memknobs [kernel.kallsyms] [k] syscall_exit
0.00% 26 memknobs [kernel.kallsyms] [k] .do_syscall_trace_leave
0.00% 26 memknobs [kernel.kallsyms] [k] .SyS_rt_sigaction
0.00% 24 memknobs [kernel.kallsyms] [k] .do_syscall_trace_enter
0.00% 22 memknobs [kernel.kallsyms] [k] .copy_from_user
0.00% 22 memknobs [kernel.kallsyms] [k] ._raw_spin_lock
0.00% 20 memknobs [kernel.kallsyms] [k] .ret_from_except_lite
0.00% 20 memknobs [kernel.kallsyms] [k] .arch_local_irq_restore
0.00% 18 memknobs [kernel.kallsyms] [k] .account_system_vtime
0.00% 18 memknobs [kernel.kallsyms] [k] .run_posix_cpu_timers
0.00% 18 memknobs [kernel.kallsyms] [k] ._raw_spin_lock_irqsave
0.00% 17 memknobs libc-2.14.90.so [.] __GI___sigaction
0.00% 17 memknobs [kernel.kallsyms] [k] .__copy_tofrom_user
0.00% 17 memknobs [kernel.kallsyms] [k] ._cond_resched
0.00% 15 memknobs [kernel.kallsyms] [k] syscall_dotrace
0.00% 15 memknobs [kernel.kallsyms] [k] .kfree
0.00% 13 memknobs [kernel.kallsyms] [k] .mntput
0.00% 12 memknobs [kernel.kallsyms] [k] .run_timer_softirq
0.00% 11 memknobs [kernel.kallsyms] [k] .perf_ctx_unlock
0.00% 10 memknobs [kernel.kallsyms] [k] system_call
0.00% 10 memknobs [kernel.kallsyms] [k] .__do_softirq
0.00% 10 memknobs [kernel.kallsyms] [k] .path_put
0.00% 7 memknobs libc-2.14.90.so [.] __printf_fp@@GLIBC_2.4
0.00% 6 memknobs [kernel.kallsyms] [k] system_call_entry
0.00% 6 memknobs [kernel.kallsyms] [k] .ret_from_except
0.00% 6 memknobs [kernel.kallsyms] [k] .copy_to_user
0.00% 6 memknobs [kernel.kallsyms] [k] .cpuacct_update_stats
0.00% 5 memknobs memknobs [.] 00000011.plt_call.signal
0.00% 5 memknobs libc-2.14.90.so [.] vfprintf@@GLIBC_2.4
0.00% 5 memknobs [kernel.kallsyms] [k] .save_nvgprs
0.00% 5 memknobs [kernel.kallsyms] [k] .do_softirq
0.00% 5 memknobs [kernel.kallsyms] [k] .timer_interrupt
0.00% 5 memknobs [kernel.kallsyms] [k] .idle_cpu
0.00% 5 memknobs [kernel.kallsyms] [k] .hrtimer_interrupt
0.00% 5 memknobs [kernel.kallsyms] [k] .profile_tick
0.00% 5 memknobs [kernel.kallsyms] [k] .acct_update_integrals
0.00% 4 memknobs [kernel.kallsyms] [k] .decrementer_set_next_ev
0.00% 4 memknobs [kernel.kallsyms] [k] .__run_hrtimer
0.00% 3 memknobs libc-2.14.90.so [.] _IO_file_xsputn@@GLIBC_2
0.00% 3 memknobs [kernel.kallsyms] [k] .flush_dcache_page
0.00% 3 memknobs [kernel.kallsyms] [k] .try_to_wake_up
0.00% 3 memknobs [kernel.kallsyms] [k] .dyntick_save_progress_c
0.00% 3 memknobs [kernel.kallsyms] [k] .__rcu_process_callbacks
0.00% 3 memknobs [kernel.kallsyms] [k] .path_init
0.00% 3 memknobs [kernel.kallsyms] [k] .avtab_search_node
0.00% 3 memknobs [kernel.kallsyms] [k] .find_next_bit
0.00% 3 memknobs [kernel.kallsyms] [k] .mix_pool_bytes_extract
0.00% 2 memknobs memknobs [.] elapsed
0.00% 2 memknobs libc-2.14.90.so [.] _IO_default_xsputn
0.00% 2 memknobs [kernel.kallsyms] [k] fp_unavailable_common
0.00% 2 memknobs [kernel.kallsyms] [.] .sched_clock
0.00% 2 memknobs [kernel.kallsyms] [k] .copy_page
0.00% 2 memknobs [kernel.kallsyms] [k] .plpar_hcall
0.00% 2 memknobs [kernel.kallsyms] [k] .__enqueue_entity
0.00% 2 memknobs [kernel.kallsyms] [k] .account_system_time
0.00% 2 memknobs [kernel.kallsyms] [k] .rebalance_domains
0.00% 2 memknobs [kernel.kallsyms] [k] .irq_exit
0.00% 2 memknobs [kernel.kallsyms] [k] .raise_softirq
0.00% 2 memknobs [kernel.kallsyms] [k] .mod_timer
0.00% 2 memknobs [kernel.kallsyms] [k] .update_process_times
0.00% 2 memknobs [kernel.kallsyms] [k] .hrtimer_forward
0.00% 2 memknobs [kernel.kallsyms] [k] .up_read
0.00% 2 memknobs [kernel.kallsyms] [k] .tick_program_event
0.00% 2 memknobs [kernel.kallsyms] [.] .perf_prepare_sample
0.00% 2 memknobs [kernel.kallsyms] [k] .get_page_from_freelist
0.00% 2 memknobs [kernel.kallsyms] [k] .__alloc_pages_nodemask
0.00% 2 memknobs [kernel.kallsyms] [k] .release_pages
0.00% 2 memknobs [kernel.kallsyms] [k] .do_wp_page
0.00% 2 memknobs [kernel.kallsyms] [k] .__mem_cgroup_uncharge_c
0.00% 2 memknobs [kernel.kallsyms] [k] .do_sys_open
0.00% 2 memknobs [kernel.kallsyms] [k] .rb_insert_color
0.00% 2 memknobs [kernel.kallsyms] [k] .timerqueue_add
0.00% 2 memknobs [kernel.kallsyms] [k] .__list_del_entry
0.00% 2 memknobs [kernel.kallsyms] [k] .n_tty_write
0.00% 2 memknobs [kernel.kallsyms] [k] .pty_write
0.00% 2 memknobs [kernel.kallsyms] [k] .scsi_finish_command
0.00% 1 memknobs memknobs [.] __read_var
0.00% 1 memknobs libc-2.14.90.so [.] _init
0.00% 1 memknobs libc-2.14.90.so [.] __isnanl
0.00% 1 memknobs libc-2.14.90.so [.] __mpn_divrem
0.00% 1 memknobs libc-2.14.90.so [.] __mpn_rshift
0.00% 1 memknobs libc-2.14.90.so [.] __mpn_mul
0.00% 1 memknobs libc-2.14.90.so [.] _itoa_word
0.00% 1 memknobs libc-2.14.90.so [.] hack_digit.13208
0.00% 1 memknobs libc-2.14.90.so [.] new_do_write
0.00% 1 memknobs libc-2.14.90.so [.] _IO_str_init_static_inte
0.00% 1 memknobs libc-2.14.90.so [.] _dl_addr
0.00% 1 memknobs ld-2.14.90.so [.] dl_main
0.00% 1 memknobs ld-2.14.90.so [.] _dl_relocate_object
0.00% 1 memknobs ld-2.14.90.so [.] _dl_fixup
0.00% 1 memknobs [raid1] [k] .init_module
0.00% 1 memknobs [kernel.kallsyms] [k] decrementer_common
0.00% 1 memknobs [kernel.kallsyms] [.] fast_exception_return
0.00% 1 memknobs [kernel.kallsyms] [k] .load_up_fpu
0.00% 1 memknobs [kernel.kallsyms] [k] .irqd_to_hwirq
0.00% 1 memknobs [kernel.kallsyms] [k] .hash_page
0.00% 1 memknobs [kernel.kallsyms] [k] .slb_miss_kernel_load_io
0.00% 1 memknobs [kernel.kallsyms] [k] .__hash_page_64K
0.00% 1 memknobs [kernel.kallsyms] [k] .ht64_call_hpte_insert1
0.00% 1 memknobs [kernel.kallsyms] [k] ht64_write_out_pte
0.00% 1 memknobs [kernel.kallsyms] [k] .__clear_user
0.00% 1 memknobs [kernel.kallsyms] [k] .__spin_yield
0.00% 1 memknobs [kernel.kallsyms] [k] .pSeries_lpar_hpte_inser
0.00% 1 memknobs [kernel.kallsyms] [k] .pSeries_lpar_hpte_inval
0.00% 1 memknobs [kernel.kallsyms] [k] .update_cfs_load
0.00% 1 memknobs [kernel.kallsyms] [k] .calc_delta_mine
0.00% 1 memknobs [kernel.kallsyms] [k] .select_task_rq_fair
0.00% 1 memknobs [kernel.kallsyms] [k] .finish_task_switch
0.00% 1 memknobs [kernel.kallsyms] [k] .update_curr
0.00% 1 memknobs [kernel.kallsyms] [k] .check_preempt_wakeup
0.00% 1 memknobs [kernel.kallsyms] [k] .enqueue_task_fair
0.00% 1 memknobs [kernel.kallsyms] [k] .update_group_power
0.00% 1 memknobs [kernel.kallsyms] [k] .idle_task
0.00% 1 memknobs [kernel.kallsyms] [k] .jiffies_to_timeval
0.00% 1 memknobs [kernel.kallsyms] [k] .insert_work
0.00% 1 memknobs [kernel.kallsyms] [k] .wq_worker_waking_up
0.00% 1 memknobs [kernel.kallsyms] [k] .enqueue_hrtimer
0.00% 1 memknobs [kernel.kallsyms] [k] .SyS_nanosleep
0.00% 1 memknobs [kernel.kallsyms] [k] .down_read_trylock
0.00% 1 memknobs [kernel.kallsyms] [k] .ktime_get
0.00% 1 memknobs [kernel.kallsyms] [k] .clockevents_program_eve
0.00% 1 memknobs [kernel.kallsyms] [k] .tick_sched_timer
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_start_gp
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_report_qs_rnp
0.00% 1 memknobs [kernel.kallsyms] [k] .force_quiescent_state
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_process_callbacks
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_implicit_dynticks_q
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_note_context_switch
0.00% 1 memknobs [kernel.kallsyms] [k] .rcu_enter_nohz
0.00% 1 memknobs [kernel.kallsyms] [k] .update_context_time
0.00% 1 memknobs [kernel.kallsyms] [k] .__perf_event_task_sched
0.00% 1 memknobs [kernel.kallsyms] [k] .perf_event_mmap_ctx
0.00% 1 memknobs [kernel.kallsyms] [k] .find_get_page
0.00% 1 memknobs [kernel.kallsyms] [k] .mempool_free
0.00% 1 memknobs [kernel.kallsyms] [k] .get_pageblock_flags_gro
0.00% 1 memknobs [kernel.kallsyms] [k] .__rmqueue
0.00% 1 memknobs [kernel.kallsyms] [k] .next_zones_zonelist
0.00% 1 memknobs [kernel.kallsyms] [k] .__inc_zone_state
0.00% 1 memknobs [kernel.kallsyms] [k] .find_vma
0.00% 1 memknobs [kernel.kallsyms] [k] .get_unmapped_area_prot
0.00% 1 memknobs [kernel.kallsyms] [k] .page_remove_rmap
0.00% 1 memknobs [kernel.kallsyms] [k] .anon_vma_prepare
0.00% 1 memknobs [kernel.kallsyms] [k] .ptep_clear_flush
0.00% 1 memknobs [kernel.kallsyms] [k] .alloc_pages_vma
0.00% 1 memknobs [kernel.kallsyms] [k] .kmem_cache_alloc
0.00% 1 memknobs [kernel.kallsyms] [k] .__mem_cgroup_commit_cha
0.00% 1 memknobs [kernel.kallsyms] [k] .mem_cgroup_newpage_char
0.00% 1 memknobs [kernel.kallsyms] [k] .SyS_write
0.00% 1 memknobs [kernel.kallsyms] [k] .file_free_rcu
0.00% 1 memknobs [kernel.kallsyms] [k] .fget_light
0.00% 1 memknobs [kernel.kallsyms] [k] .fput
0.00% 1 memknobs [kernel.kallsyms] [k] .search_binary_handler
0.00% 1 memknobs [kernel.kallsyms] [k] .getname_flags
0.00% 1 memknobs [kernel.kallsyms] [k] .putname
0.00% 1 memknobs [kernel.kallsyms] [k] .path_openat
0.00% 1 memknobs [kernel.kallsyms] [k] .__d_lookup_rcu
0.00% 1 memknobs [kernel.kallsyms] [k] .expand_files
0.00% 1 memknobs [kernel.kallsyms] [k] .do_mpage_readpage
0.00% 1 memknobs [kernel.kallsyms] [k] .ext4_getblk
0.00% 1 memknobs [kernel.kallsyms] [k] .avc_has_perm_noaudit
0.00% 1 memknobs [kernel.kallsyms] [k] .avc_has_perm_flags
0.00% 1 memknobs [kernel.kallsyms] [k] .selinux_file_permission
0.00% 1 memknobs [kernel.kallsyms] [k] .ebitmap_get_bit
0.00% 1 memknobs [kernel.kallsyms] [k] .context_struct_compute_
0.00% 1 memknobs [kernel.kallsyms] [k] .cond_compute_av
0.00% 1 memknobs [kernel.kallsyms] [k] .cfq_completed_request
0.00% 1 memknobs [kernel.kallsyms] [k] .kobject_put
0.00% 1 memknobs [kernel.kallsyms] [k] .__bitmap_intersects
0.00% 1 memknobs [kernel.kallsyms] [k] .__percpu_counter_add
0.00% 1 memknobs [kernel.kallsyms] [k] .tty_paranoia_check
0.00% 1 memknobs [kernel.kallsyms] [k] .tty_write
0.00% 1 memknobs [kernel.kallsyms] [k] .tty_flip_buffer_push
0.00% 1 memknobs [kernel.kallsyms] [k] .scsi_log_completion
0.00% 1 memknobs [kernel.kallsyms] [k] .scsi_run_queue
0.00% 1 memknobs [kernel.kallsyms] [k] .scsi_device_unbusy
0.00% 1 memknobs [kernel.kallsyms] [k] .__schedule
0.00% 1 memknobs [kernel.kallsyms] [k] ._raw_spin_unlock_irqres
0.00% 1 memknobs [kernel.kallsyms] [k] .do_page_fault
0.00% 1 memknobs [kernel.kallsyms] [k] .__slab_free
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
[jwboyer@coho ~]$ uname -a
Linux coho.fedora.osuosl.org 3.2.6-3.fc16.ppc64 #1 SMP Fri Feb 17 21:41:20 UTC 2012 ppc64 ppc64 ppc64 GNU/Linux
[jwboyer@coho ~]$
Given F16 is on the 3.2 kernel series now, I think this is fixed.
|
== Comment: #0 - Maynard P. Johnson <mpjohn.com> - 2011.10.27 13:35:45 == The version of perf on my F16 ppc64 box is 3.1.0-0.rc9.git0.2.fc16.kh.ppc64. The command I use to collect profile data is: perf record -f -e cycles -c 100000 ./memcpyt 300000000 where memcpyt is a simple test program that does a lot of memcpy's. The output from 'perf report -n --stdio' is: # Events: 209K cycles # # Overhead Samples Command Shared Object Symbol # ........ .......... ....... ................. ..................................... # 100.00% 1 memcpyt libc-2.14.90.so [.] __printf_fp@@GLIBC_2.4 100.00% 1 memcpyt ld-2.14.90.so [.] do_lookup_x 100.00% 1 memcpyt ld-2.14.90.so [.] strcmp 100.00% 1 memcpyt [kernel.kallsyms] [k] decrementer_common ............................ 100.00% 7 memcpyt [kernel.kallsyms] [k] .jiffies_to_timeval 100.00% 7 memcpyt [kernel.kallsyms] [k] .__do_softirq 100.00% 8 memcpyt [kernel.kallsyms] [k] .timer_interrupt ............................. 100.00% 5305 memcpyt memcpyt [.] 00000011.plt_call.memcpy@@GLIBC_2.3+0 100.00% 62608 memcpyt memcpyt [.] do_my_memcpy 100.00% 139466 memcpyt libc-2.14.90.so [.] memcpy Note the reversed order (lowest number of samples at the top) and the fact that all lines are listed as 100% overhead. I tried --sort=symbol; the order changed, but it still did not yield correct results.