https://perf.wiki.kernel.org/index.php?title=Perf_examples&feed=atom&action=history
Perf examples - Revision history
2024-03-29T12:19:18Z
Revision history for this page on the wiki
MediaWiki 1.19.24
https://perf.wiki.kernel.org/index.php?title=Perf_examples&diff=1309&oldid=prev
Bpetkov: add 'perf list' hint for mounted debugfs
2009-11-08T16:59:15Z
<p>add 'perf list' hint for mounted debugfs</p>
<table class='diff diff-contentalign-left'>
<col class='diff-marker' />
<col class='diff-content' />
<col class='diff-marker' />
<col class='diff-content' />
<tr valign='top'>
<td colspan='2' style="background-color: white; color:black;">← Older revision</td>
<td colspan='2' style="background-color: white; color:black;">Revision as of 16:59, 8 November 2009</td>
</tr><tr><td colspan="2" class="diff-lineno">Line 1:</td>
<td colspan="2" class="diff-lineno">Line 1:</td></tr>
<tr><td class='diff-marker'>−</td><td style="background: #ffa; color:black; font-size: smaller;"><div>First, discovery/enumeration of available counters can be done via  </div></td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div>First, discovery/enumeration of available counters can be done via 'perf</div></td></tr>
<tr><td class='diff-marker'>−</td><td style="background: #ffa; color:black; font-size: smaller;"><div>'perf list':</div></td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div>list'<ins class="diffchange diffchange-inline">. (For the tracepoint events you will need to have debugfs mounted</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins class="diffchange diffchange-inline">first, e.g. <tt>mount -t debugfs none /dbg</tt>)</ins>:</div></td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"></td></tr>
<tr><td class='diff-marker'>−</td><td style="background: #ffa; color:black; font-size: smaller;"><div>titan:~> perf list</div></td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins class="diffchange diffchange-inline"> </ins>titan:~> perf list</div></td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>   [...]</div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>   [...]</div></td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>   kmem:kmalloc                            [Tracepoint event]</div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>   kmem:kmalloc                            [Tracepoint event]</div></td></tr>
</table>
Bpetkov
https://perf.wiki.kernel.org/index.php?title=Perf_examples&diff=1301&oldid=prev
Crmafra at 23:04, 7 September 2009
2009-09-07T23:04:01Z
<p></p>
<table class='diff diff-contentalign-left'>
<col class='diff-marker' />
<col class='diff-content' />
<col class='diff-marker' />
<col class='diff-content' />
<tr valign='top'>
<td colspan='2' style="background-color: white; color:black;">← Older revision</td>
<td colspan='2' style="background-color: white; color:black;">Revision as of 23:04, 7 September 2009</td>
</tr><tr><td colspan="2" class="diff-lineno">Line 214:</td>
<td colspan="2" class="diff-lineno">Line 214:</td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>     0.78%              git  [kernel]                  [k] hpet_next_event</div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>     0.78%              git  [kernel]                  [k] hpet_next_event</div></td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>  so yeah, SHA1 performance matters.</div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>  so yeah, SHA1 performance matters.</div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">== Measuring latency ==</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">(from http://marc.info/?l=linux-kernel&m=125236192700449&w=2)</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">btw., if you run -tip and have these enabled:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  CONFIG_PERF_COUNTER=y </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  CONFIG_EVENT_TRACING=y</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  cd tools/perf/</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  make -j install</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">... then you can use a couple of new perfcounters features to </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">measure scheduler latencies. For example:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  perf stat -e sched:sched_stat_wait -e task-clock ./hackbench 20</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">Will tell you how many times this workload got delayed by waiting </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">for CPU time.</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">You can repeat the workload as well and see the statistical </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">properties of those metrics:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> aldebaran:/home/mingo> perf stat --repeat 10 -e \</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">              sched:sched_stat_wait:r -e task-clock ./hackbench 20</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.251</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.214</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.254</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.278</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.245</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.308</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.242</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.222</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.268</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Time: 0.244</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> Performance counter stats for './hackbench 20' (10 runs):</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">          59826  sched:sched_stat_wait    #      0.026 M/sec  ( +-  5.540% )</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    2280.099643  task-clock-msecs        #      7.525 CPUs    ( +-  1.620% )</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    0.303013390  seconds time elapsed  ( +-  3.189% )</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">To get scheduling events, do:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> # perf list 2>&1 | grep sched:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_kthread_stop                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_kthread_stop_ret              [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_wait_task                      [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_wakeup                        [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_wakeup_new                    [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_switch                        [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_migrate_task                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_process_free                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_process_exit                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_process_wait                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_process_fork                  [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_signal_send                    [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_stat_wait                      [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_stat_sleep                    [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  sched:sched_stat_iowait                    [Tracepoint event]</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">stat_wait/sleep/iowait would be the interesting ones, for latency </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">analysis.</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">Or, if you want to see all the specific delays and want to see </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">min/max/avg, you can do:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  perf record -e sched:sched_stat_wait:r -f -R -c 1 ./hackbench 20</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">  perf trace</ins></div></td></tr>
</table>
Crmafra
https://perf.wiki.kernel.org/index.php?title=Perf_examples&diff=1288&oldid=prev
Crmafra: A usage example from Linus
2009-08-06T11:50:19Z
<p>A usage example from Linus</p>
<table class='diff diff-contentalign-left'>
<col class='diff-marker' />
<col class='diff-content' />
<col class='diff-marker' />
<col class='diff-content' />
<tr valign='top'>
<td colspan='2' style="background-color: white; color:black;">← Older revision</td>
<td colspan='2' style="background-color: white; color:black;">Revision as of 11:50, 6 August 2009</td>
</tr><tr><td colspan="2" class="diff-lineno">Line 192:</td>
<td colspan="2" class="diff-lineno">Line 192:</td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>( this shows that 83.42% of __GI___fork's page allocations come from  </div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>( this shows that 83.42% of __GI___fork's page allocations come from  </div></td></tr>
<tr><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>the 0x38 system call it performs. )</div></td><td class='diff-marker'> </td><td style="background: #eee; color:black; font-size: smaller;"><div>the 0x38 system call it performs. )</div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">== Is it worth optimizing some particular function? ==</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">Suppose you want to know whether optimizing some particular function </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">in your program is worth the effort. For example, in the git mailing list</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">the idea of optimizing the SHA1 encryption routine came up, and one can</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">use 'perf' to decide about it.</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">See Linus' reply [http://thread.gmane.org/gmane.comp.version-control.git/124745]:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"></ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> "perf report --sort comm,dso,symbol" profiling shows the following for </ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> 'git fsck --full' on the kernel repo, using the Mozilla SHA1:</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    47.69%              git  /home/torvalds/git/git    [.] moz_SHA1_Update</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    22.98%              git  /lib64/libz.so.1.2.3      [.] inflate_fast</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    7.32%              git  /lib64/libc-2.10.1.so      [.] __GI_memcpy</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    4.66%              git  /lib64/libz.so.1.2.3      [.] inflate</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    3.76%              git  /lib64/libz.so.1.2.3      [.] adler32</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    2.86%              git  /lib64/libz.so.1.2.3      [.] inflate_table</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    2.41%              git  /home/torvalds/git/git    [.] lookup_object</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    1.31%              git  /lib64/libc-2.10.1.so      [.] _int_malloc</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    0.84%              git  /home/torvalds/git/git    [.] patch_delta</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;">    0.78%              git  [kernel]                  [k] hpet_next_event</ins></div></td></tr>
<tr><td colspan="2"> </td><td class='diff-marker'>+</td><td style="background: #cfc; color:black; font-size: smaller;"><div><ins style="color: red; font-weight: bold; text-decoration: none;"> so yeah, SHA1 performance matters.</ins></div></td></tr>
</table>
Crmafra
https://perf.wiki.kernel.org/index.php?title=Perf_examples&diff=1286&oldid=prev
Crmafra: These examples were written by Ingo Molnar in http://lkml.org/lkml/2009/8/4/346
2009-08-06T08:58:31Z
<p>These examples were written by Ingo Molnar in http://lkml.org/lkml/2009/8/4/346</p>
<p><b>New page</b></p><div>First, discovery/enumeration of available counters can be done via <br />
'perf list':<br />
<br />
titan:~> perf list<br />
[...]<br />
kmem:kmalloc [Tracepoint event]<br />
kmem:kmem_cache_alloc [Tracepoint event]<br />
kmem:kmalloc_node [Tracepoint event]<br />
kmem:kmem_cache_alloc_node [Tracepoint event]<br />
kmem:kfree [Tracepoint event]<br />
kmem:kmem_cache_free [Tracepoint event]<br />
kmem:mm_page_free_direct [Tracepoint event]<br />
kmem:mm_pagevec_free [Tracepoint event]<br />
kmem:mm_page_alloc [Tracepoint event]<br />
kmem:mm_page_alloc_zone_locked [Tracepoint event]<br />
kmem:mm_page_pcpu_drain [Tracepoint event]<br />
kmem:mm_page_alloc_extfrag [Tracepoint event]<br />
<br />
Then any (or all) of the above event sources can be activated and <br />
measured. For example the page alloc/free properties of a 'hackbench <br />
run' are:<br />
<br />
titan:~> perf stat -e kmem:mm_page_pcpu_drain -e kmem:mm_page_alloc <br />
-e kmem:mm_pagevec_free -e kmem:mm_page_free_direct ./hackbench 10<br />
Time: 0.575<br />
Performance counter stats for './hackbench 10':<br />
13857 kmem:mm_page_pcpu_drain <br />
27576 kmem:mm_page_alloc <br />
6025 kmem:mm_pagevec_free <br />
20934 kmem:mm_page_free_direct<br />
0.613972165 seconds time elapsed<br />
<br />
You can observe the statistical properties as well, by using the <br />
'repeat the workload N times' feature of perf stat:<br />
<br />
titan:~> perf stat --repeat 5 -e kmem:mm_page_pcpu_drain -e <br />
kmem:mm_page_alloc -e kmem:mm_pagevec_free -e <br />
kmem:mm_page_free_direct ./hackbench 10<br />
Time: 0.627<br />
Time: 0.644<br />
Time: 0.564<br />
Time: 0.559<br />
Time: 0.626<br />
<br />
Performance counter stats for './hackbench 10' (5 runs):<br />
12920 kmem:mm_page_pcpu_drain ( +- 3.359% )<br />
25035 kmem:mm_page_alloc ( +- 3.783% )<br />
6104 kmem:mm_pagevec_free ( +- 0.934% )<br />
18376 kmem:mm_page_free_direct ( +- 4.941% )<br />
0.643954516 seconds time elapsed ( +- 2.363% )<br />
<br />
Furthermore, these tracepoints can be used to sample the workload as <br />
well. For example the page allocations done by a 'git gc' can be <br />
captured the following way:<br />
<br />
titan:~/git> perf record -f -e kmem:mm_page_alloc -c 1 ./git gc<br />
Counting objects: 1148, done.<br />
Delta compression using up to 2 threads.<br />
Compressing objects: 100% (450/450), done.<br />
Writing objects: 100% (1148/1148), done.<br />
Total 1148 (delta 690), reused 1148 (delta 690)<br />
[ perf record: Captured and wrote 0.267 MB perf.data (~11679 samples) ]<br />
<br />
To check which functions generated page allocations:<br />
<br />
titan:~/git> perf report<br />
# Samples: 10646<br />
#<br />
# Overhead Command Shared Object<br />
# ........ ............... ..........................<br />
#<br />
23.57% git-repack /lib64/libc-2.5.so <br />
21.81% git /lib64/libc-2.5.so <br />
14.59% git ./git <br />
11.79% git-repack ./git <br />
7.12% git /lib64/ld-2.5.so <br />
3.16% git-repack /lib64/libpthread-2.5.so <br />
2.09% git-repack /bin/bash <br />
1.97% rm /lib64/libc-2.5.so <br />
1.39% mv /lib64/ld-2.5.so <br />
1.37% mv /lib64/libc-2.5.so <br />
1.12% git-repack /lib64/ld-2.5.so <br />
0.95% rm /lib64/ld-2.5.so <br />
0.90% git-update-serv /lib64/libc-2.5.so <br />
0.73% git-update-serv /lib64/ld-2.5.so <br />
0.68% perf /lib64/libpthread-2.5.so <br />
0.64% git-repack /usr/lib64/libz.so.1.2.3 <br />
<br />
Or to see it on a more finegrained level:<br />
<br />
titan:~/git> perf report --sort comm,dso,symbol<br />
# Samples: 10646<br />
#<br />
# Overhead Command Shared Object Symbol<br />
# ........ ............... .......................... ......<br />
#<br />
9.35% git-repack ./git [.] insert_obj_hash<br />
9.12% git ./git [.] insert_obj_hash<br />
7.31% git /lib64/libc-2.5.so [.] memcpy<br />
6.34% git-repack /lib64/libc-2.5.so [.] _int_malloc<br />
6.24% git-repack /lib64/libc-2.5.so [.] memcpy<br />
5.82% git-repack /lib64/libc-2.5.so [.] __GI___fork<br />
5.47% git /lib64/libc-2.5.so [.] _int_malloc<br />
2.99% git /lib64/libc-2.5.so [.] memset<br />
<br />
Furthermore, call-graph sampling can be done too, of page <br />
allocations - to see precisely what kind of page allocations there <br />
are:<br />
<br />
titan:~/git> perf record -f -g -e kmem:mm_page_alloc -c 1 ./git gc<br />
Counting objects: 1148, done.<br />
Delta compression using up to 2 threads.<br />
Compressing objects: 100% (450/450), done.<br />
Writing objects: 100% (1148/1148), done.<br />
Total 1148 (delta 690), reused 1148 (delta 690)<br />
[ perf record: Captured and wrote 0.963 MB perf.data (~42069 samples) ]<br />
<br />
titan:~/git> perf report -g<br />
# Samples: 10686<br />
#<br />
# Overhead Command Shared Object<br />
# ........ ............... ..........................<br />
#<br />
23.25% git-repack /lib64/libc-2.5.so <br />
| <br />
|--50.00%-- _int_free<br />
| <br />
|--37.50%-- __GI___fork<br />
| make_child<br />
| <br />
|--12.50%-- ptmalloc_unlock_all2<br />
| make_child<br />
| <br />
--6.25%-- __GI_strcpy<br />
21.61% git /lib64/libc-2.5.so <br />
| <br />
|--30.00%-- __GI_read<br />
| | <br />
| --83.33%-- git_config_from_file<br />
| git_config<br />
| | <br />
[...]<br />
<br />
Or you can observe the whole system's page allocations for 10 <br />
seconds:<br />
<br />
titan:~/git> perf stat -a -e kmem:mm_page_pcpu_drain -e <br />
kmem:mm_page_alloc -e kmem:mm_pagevec_free -e <br />
kmem:mm_page_free_direct sleep 10<br />
Performance counter stats for 'sleep 10':<br />
<br />
171585 kmem:mm_page_pcpu_drain <br />
322114 kmem:mm_page_alloc <br />
73623 kmem:mm_pagevec_free <br />
254115 kmem:mm_page_free_direct<br />
10.000591410 seconds time elapsed<br />
<br />
Or observe how fluctuating the page allocations are, via statistical <br />
analysis done over ten 1-second intervals:<br />
<br />
titan:~/git> perf stat --repeat 10 -a -e kmem:mm_page_pcpu_drain -e <br />
kmem:mm_page_alloc -e kmem:mm_pagevec_free -e <br />
kmem:mm_page_free_direct sleep 1<br />
<br />
Performance counter stats for 'sleep 1' (10 runs):<br />
17254 kmem:mm_page_pcpu_drain ( +- 3.709% )<br />
34394 kmem:mm_page_alloc ( +- 4.617% )<br />
7509 kmem:mm_pagevec_free ( +- 4.820% )<br />
25653 kmem:mm_page_free_direct ( +- 3.672% )<br />
1.058135029 seconds time elapsed ( +- 3.089% )<br />
<br />
Or you can annotate the recorded 'git gc' run on a per symbol basis <br />
and check which instructions/source-code generated page allocations:<br />
<br />
titan:~/git> perf annotate __GI___fork<br />
------------------------------------------------<br />
Percent | Source code & Disassembly of libc-2.5.so<br />
------------------------------------------------<br />
:<br />
:<br />
: Disassembly of section .plt:<br />
: Disassembly of section .text:<br />
:<br />
: 00000031a2e95560 <__fork>:<br />
[...]<br />
0.00 : 31a2e95602: b8 38 00 00 00 mov $0x38,%eax<br />
0.00 : 31a2e95607: 0f 05 syscall <br />
83.42 : 31a2e95609: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax<br />
0.00 : 31a2e9560f: 0f 87 4d 01 00 00 ja 31a2e95762 <__fork+0x202><br />
0.00 : 31a2e95615: 85 c0 test %eax,%eax<br />
<br />
( this shows that 83.42% of __GI___fork's page allocations come from <br />
the 0x38 system call it performs. )</div>
Crmafra