Bug 749626 - perf report output is in reverse order
Summary: perf report output is in reverse order
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 16
Hardware: ppc64
OS: All
unspecified
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-10-27 17:50 UTC by IBM Bug Proxy
Modified: 2012-02-29 19:03 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-02-29 18:53:39 UTC
Type: ---


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
IBM Linux Technology Center 76287 0 None None None Never

Description IBM Bug Proxy 2011-10-27 17:50:57 UTC
== 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.

Comment 1 IBM Bug Proxy 2011-11-01 16:40:32 UTC
------- 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
...

Comment 2 Josh Boyer 2011-11-02 15:35:07 UTC
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.

Comment 3 IBM Bug Proxy 2012-01-16 22:29:53 UTC
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.

Comment 4 Josh Boyer 2012-02-29 18:53:39 UTC
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.


Note You need to log in before you can comment on or make changes to this bug.