Linux性能分析工具perf詳解

測(cè)試環(huán)境：Ubuntu16.04 + Kernel：4.4.0-31

系統(tǒng)級(jí)性能優(yōu)化通常包括兩個(gè)階段：性能剖析（performance profiling）和代碼優(yōu)化。

性能剖析的目標(biāo)是尋找性能瓶頸，查找引發(fā)性能問(wèn)題的原因及熱點(diǎn)代碼。

代碼優(yōu)化的目標(biāo)是針對(duì)具體性能問(wèn)題而優(yōu)化代碼或編譯選項(xiàng)，以改善軟件性能。

?

在性能剖析階段，需要借助于現(xiàn)有的profiling工具，如perf等。在代碼優(yōu)化階段往往需要借助開(kāi)發(fā)者的經(jīng)驗(yàn)，編寫(xiě)簡(jiǎn)潔高效的代碼，甚至在匯編級(jí)別合理使用各種指令，合理安排各種指令的執(zhí)行順序。

perf是一款Linux性能分析工具。Linux性能計(jì)數(shù)器是一個(gè)新的基于內(nèi)核的子系統(tǒng)，它提供一個(gè)性能分析框架，比如硬件（CPU、PMU(Performance Monitoring Unit)）功能和軟件(軟件計(jì)數(shù)器、tracepoint)功能。

通過(guò)perf，應(yīng)用程序可以利用PMU、tracepoint和內(nèi)核中的計(jì)數(shù)器來(lái)進(jìn)行性能統(tǒng)計(jì)。它不但可以分析制定應(yīng)用程序的性能問(wèn)題（per thread），也可以用來(lái)分析內(nèi)核的性能問(wèn)題，當(dāng)然也可以同事分析應(yīng)用程序和內(nèi)核，從而全面理解應(yīng)用程序中的性能瓶頸。

使用perf，可以分析程序運(yùn)行期間發(fā)生的硬件事件，比如instructions retired、processor clock cycles等；也可以分析軟件時(shí)間，比如page fault和進(jìn)程切換。

perf是一款綜合性分析工具，大到系統(tǒng)全局性性能，再小到進(jìn)程線程級(jí)別，甚至到函數(shù)及匯編級(jí)別。

perf提供了十八般武器，可以拿大刀大卸八塊，也可以拿起手術(shù)刀細(xì)致分析。

1. 背景知識(shí)

1.1 tracepoints

tracepoints是散落在內(nèi)核源碼中的一些hook，它們可以在特定的代碼被執(zhí)行到時(shí)觸發(fā)，這一特定可以被各種trace/debug工具所使用。

perf將tracepoint產(chǎn)生的時(shí)間記錄下來(lái)，生成報(bào)告，通過(guò)分析這些報(bào)告，條有人緣便可以了解程序運(yùn)行期間內(nèi)核的各種細(xì)節(jié)，對(duì)性能癥狀做出準(zhǔn)確的診斷。

這些tracepint的對(duì)應(yīng)的sysfs節(jié)點(diǎn)在/sys/kernel/debug/tracing/events目錄下。

1.2 硬件特性之cache

內(nèi)存讀寫(xiě)是很快的，但是還是無(wú)法和處理器指令執(zhí)行速度相比。為了從內(nèi)存中讀取指令和數(shù)據(jù)，處理器需要等待，用處理器時(shí)間來(lái)衡量，這種等待非常漫長(zhǎng)。cache是一種SRAM，讀寫(xiě)速度非常快，能和處理器相匹配。因此將常用的數(shù)據(jù)保存在cache中，處理器便無(wú)需等待，從而提高性能。cache的尺寸一般都很小，充分利用cache是軟件調(diào)優(yōu)非常重要部分。

2. 主要關(guān)注點(diǎn)

基于性能分析，可以進(jìn)行算法優(yōu)化（空間復(fù)雜度和時(shí)間復(fù)雜度權(quán)衡）、代碼優(yōu)化（提高執(zhí)行速度、減少內(nèi)存占用）。

評(píng)估程序?qū)τ布Y源的使用情況，例如各級(jí)cache的訪問(wèn)次數(shù)、各級(jí)cache的丟失次數(shù)、流水線停頓周期、前端總線訪問(wèn)次數(shù)等。

評(píng)估程序?qū)?a href="http://ttokpm.com/v/tag/527/" target="_blank">操作系統(tǒng)資源的使用情況，系統(tǒng)調(diào)用次數(shù)、上下文切換次數(shù)、任務(wù)遷移次數(shù)。

事件可以分為三種：

Hardware Event由PMU部件產(chǎn)生，在特定的條件下探測(cè)性能事件是否發(fā)生以及發(fā)生的次數(shù)。比如cache命中。

Software Event是內(nèi)核產(chǎn)生的事件，分布在各個(gè)功能模塊中，統(tǒng)計(jì)和操作系統(tǒng)相關(guān)性能事件。比如進(jìn)程切換，tick數(shù)等。

Tracepoint Event是內(nèi)核中靜態(tài)tracepoint所觸發(fā)的事件，這些tracepoint用來(lái)判斷程序運(yùn)行期間內(nèi)核的行為細(xì)節(jié)，比如slab分配器的分配次數(shù)等。

3. perf的使用

perf --help之后可以看到perf的二級(jí)命令。

全局性概況：

perf list查看當(dāng)前系統(tǒng)支持的性能事件； perf bench對(duì)系統(tǒng)性能進(jìn)行摸底； perf test對(duì)系統(tǒng)進(jìn)行健全性測(cè)試； perf stat對(duì)全局性能進(jìn)行統(tǒng)計(jì)；

全局細(xì)節(jié)：

perf top可以實(shí)時(shí)查看當(dāng)前系統(tǒng)進(jìn)程函數(shù)占用率情況； perf probe可以自定義動(dòng)態(tài)事件；

特定功能分析：

perf kmem針對(duì)slab子系統(tǒng)性能分析； perf kvm針對(duì)kvm虛擬化分析； perf lock分析鎖性能； perf mem分析內(nèi)存slab性能； perf sched分析內(nèi)核調(diào)度器性能； perf trace記錄系統(tǒng)調(diào)用軌跡；

最常用功能perf record，可以系統(tǒng)全局，也可以具體到某個(gè)進(jìn)程，更甚具體到某一進(jìn)程某一事件；可宏觀，也可以很微觀。

pref record記錄信息到perf.data； perf report生成報(bào)告； perf diff對(duì)兩個(gè)記錄進(jìn)行diff； perf evlist列出記錄的性能事件； perf annotate顯示perf.data函數(shù)代碼； perf archive將相關(guān)符號(hào)打包，方便在其它機(jī)器進(jìn)行分析； perf script將perf.data輸出可讀性文本；

可視化工具perf timechart

perf timechart record記錄事件； perf timechart生成output.svg文檔；

3.0 perf引入的overhead

perf測(cè)試不可避免的會(huì)引入額外負(fù)荷，有三種形式：

counting：內(nèi)核提供計(jì)數(shù)總結(jié)，多是Hardware Event、Software Events、PMU計(jì)數(shù)等。相關(guān)命令perf stat。

sampling：perf將事件數(shù)據(jù)緩存到一塊buffer中，然后異步寫(xiě)入到perf.data文件中。使用perf report等工具進(jìn)行離線分析。

bpf：Kernel 4.4+新增功能，可以提供更多有效filter和輸出總結(jié)。

counting引入的額外負(fù)荷最小；sampling在某些情況下會(huì)引入非常大的負(fù)荷；bpf可以有效縮減負(fù)荷。

針對(duì)sampling，可以通過(guò)掛在建立在RAM上的文件系統(tǒng)來(lái)有效降低讀寫(xiě)I/O引入的負(fù)荷。

mkdir /tmpfs mount -t tmpfs tmpfs /tmpfs

3.1 perf list

perf list不能完全顯示所有支持的事件類型，需要sudo perf list。

同時(shí)還可以顯示特定模塊支持的perf事件：hw/cache/pmu都是硬件相關(guān)的；tracepoint基于內(nèi)核的ftrace；sw實(shí)際上是內(nèi)核計(jì)數(shù)器。

hw/hardware顯示支持的硬件事件相關(guān)，如：

al@al-System-Product-Name:~/perf$ sudo perf list hardware List of pre-defined events (to be used in -e): branch-instructions OR branches [Hardware event] branch-misses [Hardware event] cache-misses [Hardware event] cache-references [Hardware event] cpu-cycles OR cycles [Hardware event] instructions [Hardware event] stalled-cycles-backend OR idle-cycles-backend [Hardware event] stalled-cycles-frontend OR idle-cycles-frontend [Hardware event]

sw/software顯示支持的軟件事件列表：

al@al-System-Product-Name:~/perf$ sudo perf list sw List of pre-defined events (to be used in -e): alignment-faults [Software event] bpf-output [Software event] context-switches OR cs [Software event] cpu-clock [Software event] cpu-migrations OR migrations [Software event] dummy [Software event] emulation-faults [Software event] major-faults [Software event] minor-faults [Software event] page-faults OR faults [Software event] task-clock [Software event]

cache/hwcache顯示硬件cache相關(guān)事件列表：

al@al-System-Product-Name:~/perf$ sudo perf list cache List of pre-defined events (to be used in -e): L1-dcache-load-misses [Hardware cache event] L1-dcache-loads [Hardware cache event] L1-dcache-prefetch-misses [Hardware cache event] L1-dcache-prefetches [Hardware cache event] L1-icache-load-misses [Hardware cache event] L1-icache-loads [Hardware cache event] L1-icache-prefetches [Hardware cache event] LLC-load-misses [Hardware cache event] LLC-loads [Hardware cache event] LLC-stores [Hardware cache event] branch-load-misses [Hardware cache event] branch-loads [Hardware cache event] dTLB-load-misses [Hardware cache event] dTLB-loads [Hardware cache event] iTLB-load-misses [Hardware cache event] iTLB-loads [Hardware cache event] node-load-misses [Hardware cache event] node-loads [Hardware cache event]

pmu顯示支持的PMU事件列表：

al@al-System-Product-Name:~/perf$ sudo perf list pmu List of pre-defined events (to be used in -e): branch-instructions OR cpu/branch-instructions/ [Kernel PMU event] branch-misses OR cpu/branch-misses/ [Kernel PMU event] cache-misses OR cpu/cache-misses/ [Kernel PMU event] cache-references OR cpu/cache-references/ [Kernel PMU event] cpu-cycles OR cpu/cpu-cycles/ [Kernel PMU event] instructions OR cpu/instructions/ [Kernel PMU event] msr/aperf/ [Kernel PMU event] msr/mperf/ [Kernel PMU event] msr/tsc/ [Kernel PMU event] stalled-cycles-backend OR cpu/stalled-cycles-backend/ [Kernel PMU event] stalled-cycles-frontend OR cpu/stalled-cycles-frontend/ [Kernel PMU event]

tracepoint顯示支持的所有tracepoint列表，這個(gè)列表就比較龐大：

al@al-System-Product-Name:~/perf$ sudo perf list tracepoint List of pre-defined events (to be used in -e): alarmtimer:alarmtimer_cancel [Tracepoint event] alarmtimer:alarmtimer_fired [Tracepoint event] alarmtimer:alarmtimer_start [Tracepoint event] alarmtimer:alarmtimer_suspend [Tracepoint event] block:block_bio_backmerge [Tracepoint event] block:block_bio_bounce [Tracepoint event] block:block_bio_complete [Tracepoint event] block:block_bio_frontmerge [Tracepoint event] block:block_bio_queue [Tracepoint event] …

3.2 perf top

默認(rèn)情況下perf top是無(wú)法顯示信息的，需要sudo perf top或者echo -1 > /proc/sys/kernel/perf_event_paranoid(在Ubuntu16.04，還需要echo 0 > /proc/sys/kernel/kptr_restrict)。

即可以正常顯示perf top如下：

第一列：符號(hào)引發(fā)的性能事件的比例，指占用的cpu周期比例。

第二列：符號(hào)所在的DSO(Dynamic Shared Object)，可以是應(yīng)用程序、內(nèi)核、動(dòng)態(tài)鏈接庫(kù)、模塊。

第三列：DSO的類型。[.]表示此符號(hào)屬于用戶態(tài)的ELF文件，包括可執(zhí)行文件與動(dòng)態(tài)鏈接庫(kù)；[k]表述此符號(hào)屬于內(nèi)核或模塊。

第四列：符號(hào)名。有些符號(hào)不能解析為函數(shù)名，只能用地址表示。

?

?

?

關(guān)于perf top界面常用命令如下：

h：顯示幫助，即可顯示詳細(xì)的幫助信息。 UP/DOWN/PGUP/PGDN/SPACE：上下和翻頁(yè)。 a：annotate current symbol，注解當(dāng)前符號(hào)。能夠給出匯編語(yǔ)言的注解，給出各條指令的采樣率。 d：過(guò)濾掉所有不屬于此DSO的符號(hào)。非常方便查看同一類別的符號(hào)。 P：將當(dāng)前信息保存到perf.hist.N中。

perf top常用選項(xiàng)有：

-e ：指明要分析的性能事件。 -p ：Profile events on existing Process ID (comma sperated list). 僅分析目標(biāo)進(jìn)程及其創(chuàng)建的線程。 -k ：Path to vmlinux. Required for annotation functionality. 帶符號(hào)表的內(nèi)核映像所在的路徑。 -K：不顯示屬于內(nèi)核或模塊的符號(hào)。 -U：不顯示屬于用戶態(tài)程序的符號(hào)。 -d ：界面的刷新周期，默認(rèn)為2s，因?yàn)閜erf top默認(rèn)每2s從mmap的內(nèi)存區(qū)域讀取一次性能數(shù)據(jù)。 -g：得到函數(shù)的調(diào)用關(guān)系圖。

perf top --call-graph [fractal]，路徑概率為相對(duì)值，加起來(lái)為100%，調(diào)用順序?yàn)閺南峦稀?/p>

perf top --call-graph graph，路徑概率為絕對(duì)值，加起來(lái)為該函數(shù)的熱度。

?

?

3.3 perf stat

perf stat用于運(yùn)行指令，并分析其統(tǒng)計(jì)結(jié)果。雖然perf top也可以指定pid，但是必須先啟動(dòng)應(yīng)用才能查看信息。

perf stat能完整統(tǒng)計(jì)應(yīng)用整個(gè)生命周期的信息。

命令格式為：

perf stat [-e | --event=EVENT] [-a] perf stat [-e | --event=EVENT] [-a] — []

下面簡(jiǎn)單看一下perf stat 的輸出：

al@al-System-Product-Name:~/perf$ sudo perf stat ^C Performance counter stats for 'system wide': 40904.820871 cpu-clock (msec) # 5.000 CPUs utilized 18,132 context-switches # 0.443 K/sec 1,053 cpu-migrations # 0.026 K/sec 2,420 page-faults # 0.059 K/sec 3,958,376,712 cycles # 0.097 GHz (49.99%) 574,598,403 stalled-cycles-frontend # 14.52% frontend cycles idle (49.98%) 9,392,982,910 stalled-cycles-backend # 237.29% backend cycles idle (50.00%) 1,653,185,883 instructions # 0.42 insn per cycle # 5.68 stalled cycles per insn (50.01%) 237,061,366 branches # 5.795 M/sec (50.02%) 18,333,168 branch-misses # 7.73% of all branches (50.00%) 8.181521203 seconds time elapsed

輸出解釋如下：

cpu-clock：任務(wù)真正占用的處理器時(shí)間，單位為ms。CPUs utilized = task-clock / time elapsed，CPU的占用率。 context-switches：程序在運(yùn)行過(guò)程中上下文的切換次數(shù)。 CPU-migrations：程序在運(yùn)行過(guò)程中發(fā)生的處理器遷移次數(shù)。Linux為了維持多個(gè)處理器的負(fù)載均衡，在特定條件下會(huì)將某個(gè)任務(wù)從一個(gè)CPU遷移到另一個(gè)CPU。 CPU遷移和上下文切換：發(fā)生上下文切換不一定會(huì)發(fā)生CPU遷移，而發(fā)生CPU遷移時(shí)肯定會(huì)發(fā)生上下文切換。發(fā)生上下文切換有可能只是把上下文從當(dāng)前CPU中換出，下一次調(diào)度器還是將進(jìn)程安排在這個(gè)CPU上執(zhí)行。 page-faults：缺頁(yè)異常的次數(shù)。當(dāng)應(yīng)用程序請(qǐng)求的頁(yè)面尚未建立、請(qǐng)求的頁(yè)面不在內(nèi)存中，或者請(qǐng)求的頁(yè)面雖然在內(nèi)存中，但物理地址和虛擬地址的映射關(guān)系尚未建立時(shí)，都會(huì)觸發(fā)一次缺頁(yè)異常。另外TLB不命中，頁(yè)面訪問(wèn)權(quán)限不匹配等情況也會(huì)觸發(fā)缺頁(yè)異常。 cycles：消耗的處理器周期數(shù)。如果把被ls使用的cpu cycles看成是一個(gè)處理器的，那么它的主頻為2.486GHz?？梢杂胏ycles / task-clock算出。 stalled-cycles-frontend：指令讀取或解碼的質(zhì)量步驟，未能按理想狀態(tài)發(fā)揮并行左右，發(fā)生停滯的時(shí)鐘周期。 stalled-cycles-backend：指令執(zhí)行步驟，發(fā)生停滯的時(shí)鐘周期。 instructions：執(zhí)行了多少條指令。IPC為平均每個(gè)cpu cycle執(zhí)行了多少條指令。 branches：遇到的分支指令數(shù)。branch-misses是預(yù)測(cè)錯(cuò)誤的分支指令數(shù)。

其他常用參數(shù)

-a, --all-cpus 顯示所有CPU上的統(tǒng)計(jì)信息 -C, --cpu 顯示指定CPU的統(tǒng)計(jì)信息 -c, --scale scale/normalize counters -D, --delay ms to wait before starting measurement after program start -d, --detailed detailed run - start a lot of events -e, --event event selector. use 'perf list' to list available events -G, --cgroup monitor event in cgroup name only -g, --group put the counters into a counter group -I, --interval-print print counts at regular interval in ms (>= 10) -i, --no-inherit child tasks do not inherit counters -n, --null null run - dont start any counters -o, --output 輸出統(tǒng)計(jì)信息到文件 -p, --pid stat events on existing process id -r, --repeat repeat command and print average + stddev (max: 100, forever: 0) -S, --sync call sync() before starting a run -t, --tid stat events on existing thread id ...

示例

前面統(tǒng)計(jì)程序的示例，下面看一下統(tǒng)計(jì)CPU信息的示例：

執(zhí)行sudo perf stat -C 0，統(tǒng)計(jì)CPU 0的信息。想要停止后，按下Ctrl+C終止?？梢钥吹浇y(tǒng)計(jì)項(xiàng)一樣，只是統(tǒng)計(jì)對(duì)象變了。

al@al-System-Product-Name:~/perf$ sudo perf stat -C 0 ^C Performance counter stats for 'CPU(s) 0': 2517.107315 cpu-clock (msec) # 1.000 CPUs utilized 2,941 context-switches # 0.001 M/sec 109 cpu-migrations # 0.043 K/sec 38 page-faults # 0.015 K/sec 644,094,340 cycles # 0.256 GHz (49.94%) 70,425,076 stalled-cycles-frontend # 10.93% frontend cycles idle (49.94%) 965,270,543 stalled-cycles-backend # 149.86% backend cycles idle (49.94%) 623,284,864 instructions # 0.97 insn per cycle # 1.55 stalled cycles per insn (50.06%) 65,658,190 branches # 26.085 M/sec (50.06%) 3,276,104 branch-misses # 4.99% of all branches (50.06%) 2.516996126 seconds time elapsed

如果需要統(tǒng)計(jì)更多的項(xiàng)，需要使用-e，如：

perf stat -e task-clock,context-switches,cpu-migrations,page-faults,cycles,stalled-cycles-frontend,stalled-cycles-backend,instructions,branches,branch-misses,L1-dcache-loads,L1-dcache-load-misses,LLC-loads,LLC-load-misses,dTLB-loads,dTLB-load-misses ls

結(jié)果如下，關(guān)注的特殊項(xiàng)也納入統(tǒng)計(jì)。

al@al-System-Product-Name:~/perf$ sudo perf stat -e task-clock,context-switches,cpu-migrations,page-faults,cycles,stalled-cycles-frontend,stalled-cycles-backend,instructions,branches,branch-misses,L1-dcache-loads,L1-dcache-load-misses,LLC-loads,LLC-load-misses,dTLB-loads,dTLB-load-misses ls Performance counter stats for 'ls': 2.319422 task-clock (msec) # 0.719 CPUs utilized 0 context-switches # 0.000 K/sec 0 cpu-migrations # 0.000 K/sec 89 page-faults # 0.038 M/sec 2,142,386 cycles # 0.924 GHz 659,800 stalled-cycles-frontend # 30.80% frontend cycles idle 725,343 stalled-cycles-backend # 33.86% backend cycles idle 1,344,518 instructions # 0.63 insn per cycle # 0.54 stalled cycles per insn branches branch-misses L1-dcache-loads L1-dcache-load-misses LLC-loads LLC-load-misses dTLB-loads dTLB-load-misses 0.003227507 seconds time elapsed

3.4 perf bench

perf bench作為benchmark工具的通用框架，包含sched/mem/numa/futex等子系統(tǒng)，all可以指定所有。

perf bench可用于評(píng)估系統(tǒng)sched/mem等特定性能。

perf bench sched：調(diào)度器和IPC機(jī)制。包含messaging和pipe兩個(gè)功能。 perf bench mem：內(nèi)存存取性能。包含memcpy和memset兩個(gè)功能。 perf bench numa：NUMA架構(gòu)的調(diào)度和內(nèi)存處理性能。包含mem功能。 perf bench futex：futex壓力測(cè)試。包含hash/wake/wake-parallel/requeue/lock-pi功能。 perf bench all：所有bench測(cè)試的集合

3.4.1 perf bench sched all

測(cè)試messaging和pipi兩部分性能。

3.4.1.1 sched messaging評(píng)估進(jìn)程調(diào)度和核間通信

sched message 是從經(jīng)典的測(cè)試程序 hackbench 移植而來(lái)，用來(lái)衡量調(diào)度器的性能，overhead 以及可擴(kuò)展性。

該 benchmark 啟動(dòng) N 個(gè) reader/sender 進(jìn)程或線程對(duì)，通過(guò) IPC(socket 或者 pipe) 進(jìn)行并發(fā)的讀寫(xiě)。一般人們將 N 不斷加大來(lái)衡量調(diào)度器的可擴(kuò)展性。

sched message 的用法及用途和 hackbench 一樣，可以通過(guò)修改參數(shù)進(jìn)行不同目的測(cè)試：

-g, --group Specify number of groups -l, --nr_loops Specify the number of loops to run (default: 100) -p, --pipe Use pipe() instead of socketpair() -t, --thread Be multi thread instead of multi process

測(cè)試結(jié)果：

al@al-System-Product-Name:~/perf$ perf bench sched all # Running sched/messaging benchmark... # 20 sender and receiver processes per group # 10 groups == 400 processes run Total time: 0.173 [sec] # Running sched/pipe benchmark... # Executed 1000000 pipe operations between two processes Total time: 12.233 [sec] 12.233170 usecs/op 81744 ops/sec

使用pipe()和socketpair()對(duì)測(cè)試影響：

1. perf bench sched messaging # Running 'sched/messaging' benchmark: # 20 sender and receiver processes per group # 10 groups == 400 processes run Total time: 0.176 [sec] 2. perf bench sched messaging -p # Running 'sched/messaging' benchmark: # 20 sender and receiver processes per group # 10 groups == 400 processes run Total time: 0.093 [sec]

可見(jiàn)socketpair()性能要明顯低于pipe()。

3.4.1.2 sched pipe評(píng)估pipe性能

sched pipe 從 Ingo Molnar 的 pipe-test-1m.c 移植而來(lái)。當(dāng)初 Ingo 的原始程序是為了測(cè)試不同的調(diào)度器的性能和公平性的。

其工作原理很簡(jiǎn)單，兩個(gè)進(jìn)程互相通過(guò) pipe 拼命地發(fā) 1000000 個(gè)整數(shù)，進(jìn)程 A 發(fā)給 B，同時(shí) B 發(fā)給 A。因?yàn)?A 和 B 互相依賴，因此假如調(diào)度器不公平，對(duì) A 比 B 好，那么 A 和 B 整體所需要的時(shí)間就會(huì)更長(zhǎng)。

al@al-System-Product-Name:~/perf$ perf bench sched pipe # Running 'sched/pipe' benchmark: # Executed 1000000 pipe operations between two processes Total time: 12.240 [sec] 12.240411 usecs/op 81696 ops/sec

3.4.2 perf bench mem all

該測(cè)試衡量 不同版本的memcpy/memset/ 函數(shù)處理一個(gè) 1M 數(shù)據(jù)的所花費(fèi)的時(shí)間，轉(zhuǎn)換成吞吐率。

al@al-System-Product-Name:~/perf$ perf bench mem all # Running mem/memcpy benchmark... # function 'default' (Default memcpy() provided by glibc) # Copying 1MB bytes ... 1.236155 GB/sec. ..

3.4.3 perf bench futex

Futex是一種用戶態(tài)和內(nèi)核態(tài)混合機(jī)制，所以需要兩個(gè)部分合作完成，linux上提供了sys_futex系統(tǒng)調(diào)用，對(duì)進(jìn)程競(jìng)爭(zhēng)情況下的同步處理提供支持。

所有的futex同步操作都應(yīng)該從用戶空間開(kāi)始，首先創(chuàng)建一個(gè)futex同步變量，也就是位于共享內(nèi)存的一個(gè)整型計(jì)數(shù)器。

當(dāng)進(jìn)程嘗試持有鎖或者要進(jìn)入互斥區(qū)的時(shí)候，對(duì)futex執(zhí)行"down"操作，即原子性的給futex同步變量減1。如果同步變量變?yōu)?，則沒(méi)有競(jìng)爭(zhēng)發(fā)生， 進(jìn)程照常執(zhí)行。

如果同步變量是個(gè)負(fù)數(shù)，則意味著有競(jìng)爭(zhēng)發(fā)生，需要調(diào)用futex系統(tǒng)調(diào)用的futex_wait操作休眠當(dāng)前進(jìn)程。

當(dāng)進(jìn)程釋放鎖或 者要離開(kāi)互斥區(qū)的時(shí)候，對(duì)futex進(jìn)行"up"操作，即原子性的給futex同步變量加1。如果同步變量由0變成1，則沒(méi)有競(jìng)爭(zhēng)發(fā)生，進(jìn)程照常執(zhí)行。

如果加之前同步變量是負(fù)數(shù)，則意味著有競(jìng)爭(zhēng)發(fā)生，需要調(diào)用futex系統(tǒng)調(diào)用的futex_wake操作喚醒一個(gè)或者多個(gè)等待進(jìn)程。

al@al-System-Product-Name:~/perf$ perf bench futex all # Running futex/hash benchmark... Run summary [PID 3806]: 5 threads, each operating on 1024 [private] futexes for 10 secs. [thread 0] futexes: 0x4003d20 ... 0x4004d1c [ 4635648 ops/sec ] [thread 1] futexes: 0x4004d30 ... 0x4005d2c [ 4611072 ops/sec ] [thread 2] futexes: 0x4005e70 ... 0x4006e6c [ 4254515 ops/sec ] [thread 3] futexes: 0x4006fb0 ... 0x4007fac [ 4559360 ops/sec ] [thread 4] futexes: 0x40080f0 ... 0x40090ec [ 4636262 ops/sec ] Averaged 4539371 operations/sec (+- 1.60%), total secs = 10 # Running futex/wake benchmark... Run summary [PID 3806]: blocking on 5 threads (at [private] futex 0x96b52c), waking up 1 at a time. [Run 1]: Wokeup 5 of 5 threads in 0.0270 ms [Run 2]: Wokeup 5 of 5 threads in 0.0370 ms ...

3.4 perf record

運(yùn)行一個(gè)命令，并將其數(shù)據(jù)保存到perf.data中。隨后，可以使用perf report進(jìn)行分析。

perf record和perf report可以更精確的分析一個(gè)應(yīng)用，perf record可以精確到函數(shù)級(jí)別。并且在函數(shù)里面混合顯示匯編語(yǔ)言和代碼。

創(chuàng)建一個(gè)fork.c文件用于測(cè)試：

#include void test_little(void) { ?int i,j; ?for(i = 0; i < 30000000; i++) ? ?j=i; } void test_mdedium(void) { ?int i,j; ?for(i = 0; i < 60000000; i++) ? ?j=i; } void test_high(void) { ?int i,j; ?for(i = 0; i < 90000000; i++) ? ?j=i; } void test_hi(void) { ?int i,j; ?for(i = 0; i < 120000000; i++) ? ?j=i; } int main(void) { ?int i, pid, result; ?for(i = 0; i<2; i++) { ? ?result = fork(); ? ?if(result>0) ? ? ?printf("i=%d parent parent=%d current=%d child=%d\n", i, getppid(), getpid(), result); ? ?else ? ? ?printf("i=%d child parent=%d current=%d\n", i, getppid(), getpid()); ? ?if(i==0) ? ?{ ? ? ?test_little(); ? ? ?sleep(1); ? ?} else { ? ? ?test_mdedium(); ? ? ?sleep(1); ? ?} ?} ?pid = wait(NULL); ?test_high(); ?printf("pid=%d wait=%d\n", getpid(), pid); ?sleep(1); ?pid = wait(NULL); ?test_hi(); ?printf("pid=%d wait=%d\n", getpid(), pid); ?return 0; }

編譯fork.c文件gcc fork.c -o fork-g -O0，同時(shí)可以使用此方法分析是否選擇編譯優(yōu)化產(chǎn)生的結(jié)果。-g是只能callgraph功能，-O0是關(guān)閉優(yōu)化。

常用選項(xiàng)

-e record指定PMU事件 --filter event事件過(guò)濾器 -a 錄取所有CPU的事件 -p 錄取指定pid進(jìn)程的事件 -o 指定錄取保存數(shù)據(jù)的文件名 -g 使能函數(shù)調(diào)用圖功能 -C 錄取指定CPU的事件

sudo perf record -a -g ./fork：會(huì)在當(dāng)前目錄生成perf.data文件。

sudo perf report --call-graph none結(jié)果如下,后面結(jié)合perf timechart分析.

?

?

?

上圖看上去比較亂，如果想只看fork產(chǎn)生的信息：

sudo perf report --call-graph none -c fork

可以看出只顯示了fork程序的相關(guān)符號(hào)及其占用率。

?

?

?

3.5 perf report

解析perf record產(chǎn)生的數(shù)據(jù)，并給出分析結(jié)果。

常用參數(shù)：

-i 導(dǎo)入的數(shù)據(jù)文件名稱，如果沒(méi)有則默認(rèn)為perf.data -g 生成函數(shù)調(diào)用關(guān)系圖，此時(shí)內(nèi)核要打開(kāi)CONFIG_KALLSYMS；用戶空間庫(kù)或者執(zhí)行文件需要帶符號(hào)信息(not stripped)，編譯選項(xiàng)需要加上-g。 --sort 從更高層面顯示分類統(tǒng)計(jì)信息，比如： pid, comm, dso, symbol, parent, cpu,socket, srcline, weight, local_weight.

執(zhí)行sudo perf report -i perf.data，可以看出main函數(shù)所占百分比，以及funcA和funcB分別所占百分比。

在funcB執(zhí)行過(guò)程中，還產(chǎn)生了apic timer，占用了一部分cpu資源。除此之外，占比基本上是1：10。

?

?

?

funcA和funcB的占比，基本符合預(yù)期。那么進(jìn)入longa，分析一下熱點(diǎn)。

在C和匯編混合顯示界面，可以看出for循環(huán)占用了69.92%，j=i賦值占用了30.08%。

?

?

?

根據(jù)之上描述，可以看出top適合監(jiān)控整個(gè)系統(tǒng)的性能，stat比較適合單個(gè)程序的性能分析，record/report更適合對(duì)程序進(jìn)行更細(xì)粒度的分析。

注意點(diǎn)：

在使用perf report -g的時(shí)候，可能會(huì)提示Failed to open /lib/libpthread-0.9.33.2.so, continuing without symbols。

這時(shí)候通過(guò)file xxx查看，如果提示xxxx stripped表示此文件不包含符號(hào)信息，需要xxxx not stripped文件。

3.6 perf timechart

perf timechart是將之前的各種統(tǒng)計(jì)信息圖形化的一個(gè)工具。

perf timechart record 用于記錄整個(gè)系統(tǒng)或者一個(gè)應(yīng)用的事件，還可以加option記錄指定類型的事件。

perf timechart用于將perf.data轉(zhuǎn)換成SVG格式的文件，SVG可以通過(guò)Inkscape或者瀏覽器打開(kāi)。

perf timechart record可以指定特定類型的事件：

-P：記錄power相關(guān)事件 -T：記錄任務(wù)相關(guān)事件 -I：記錄io相關(guān)事件 -g：記錄函數(shù)調(diào)用關(guān)系

perf timechart用于將perf timechart record錄取的perf.data轉(zhuǎn)換成output.svg。

-w調(diào)整輸出的svg文件長(zhǎng)度，可以查看更多細(xì)節(jié)。

-p可以指定只查看某些進(jìn)程輸出，使用方式：sudo perf timechart -p test1 -p thermald

-o 指定輸出文件名 -i 指定待解析的文件名 -w 輸出SVG文件寬度 -P 只顯示power相關(guān)事件圖標(biāo) -T , --tasks-only 顯示task信息，不顯示處理器信息 -p 顯示指定進(jìn)程名稱或者PID顯示 --symfs= 指定系統(tǒng)符號(hào)表路徑 -t, --topology 根據(jù)拓?fù)浣Y(jié)構(gòu)對(duì)CPU進(jìn)行分類 --highlight= 對(duì)運(yùn)行超過(guò)特定時(shí)間的task高亮

當(dāng)線程太多影響svg解析速度的時(shí)候，可以通過(guò)-p指定特定線程進(jìn)行分析。如果需要幾個(gè)線程，每個(gè)線程采用-p xxx。

sudo perf timechart record -T ./fork && sudo perf timechart –p fork

結(jié)果如下，可以看到相關(guān)task的名稱，開(kāi)始時(shí)間/結(jié)束時(shí)間，每個(gè)時(shí)間點(diǎn)的狀態(tài)（Running/Idle/Deeper Idle/Deepest Idle/Sleeping/Waiting for Cpu /Blocked on IO）。

3.6.1 結(jié)合perf timechart和perf report分析函數(shù)占比

由perf report可知test_little、test_medium、test_high、test_hi四個(gè)函數(shù)占比分別為3.84%、12.01%、22.99%、30.43%。

有代碼可知如果以test_little為1單位，那么test_medium就為2單位，test_high為3單位，test_hi為4單位。

四個(gè)函數(shù)執(zhí)行次數(shù)分別為2、4、4、4，所以四個(gè)函數(shù)每個(gè)單位對(duì)應(yīng)CPU占比為：

test_little - 3.84%/2=1.9% test_medium - 12.01%/4/2=1.5% test_high - 22.99/4/3=1.9% test_hi - 30.43%/4/4=1.9%

基本上符合預(yù)期。

?

?
?

記錄IO事件，可以看到按應(yīng)用分類的，Disk/Network/Sync/Poll/Error信息。以及每個(gè)應(yīng)用數(shù)據(jù)吞吐量。

sudo perf timechart record -I && sudo perf timechart -w 1800。

記錄Power狀態(tài)事件，可以看到不同之處在于Idle之類的狀態(tài)里面還有細(xì)分C/C2更詳細(xì)的顯示Power狀態(tài)。

sudo perf timechart record -I && sudo perf timechart -w 1800

3.7 perf script

用于讀取perf record保存的裸trace數(shù)據(jù)。

使用方法：

perf script [] perf script [] record [] ?
perf script [] report

審核編輯：湯梓紅

還可以編寫(xiě)perl或者python腳本進(jìn)行數(shù)據(jù)分析。

3.8 perf lock

3.8.1 perf lock內(nèi)核配置

要使用此功能，內(nèi)核需要編譯選項(xiàng)的支持：CONFIG_LOCKDEP、CONFIG_LOCK_STAT。

CONFIG_LOCKDEP defines acquired and release events.

CONFIG_LOCK_STAT defines contended and acquired lock events.

CONFIG_LOCKDEP=y CONFIG_LOCK_STAT=y

3.8.2 perf lock使用

分析內(nèi)核鎖統(tǒng)計(jì)信息。

鎖是內(nèi)核用于同步的方法，一旦加了鎖，其他加鎖的內(nèi)核執(zhí)行路徑就必須等待，降低了并行。同時(shí)，如果加鎖不正確還會(huì)造成死鎖。

因此對(duì)于內(nèi)核鎖進(jìn)行分析是一項(xiàng)重要的調(diào)優(yōu)工作。

perf lock record：抓取執(zhí)行命令的lock事件信息到perf.data中 perf lock report：產(chǎn)生統(tǒng)計(jì)報(bào)告 perf lock script：顯示原始lock事件 perf lock info： -k ：sorting key，默認(rèn)為acquired，還可以按contended、wait_total、wait_max和wait_min來(lái)排序。 Name：內(nèi)核鎖的名字。 aquired：該鎖被直接獲得的次數(shù)，因?yàn)闆](méi)有其它內(nèi)核路徑占用該鎖，此時(shí)不用等待。 contended：該鎖等待后獲得的次數(shù)，此時(shí)被其它內(nèi)核路徑占用，需要等待。 total wait：為了獲得該鎖，總共的等待時(shí)間。 max wait：為了獲得該鎖，最大的等待時(shí)間。 min wait：為了獲得該鎖，最小的等待時(shí)間。

3.9 perf kmem

3.9.1 perf kmem介紹

perf kmem用于跟蹤測(cè)量?jī)?nèi)核slab分配器事件信息。 比如內(nèi)存分配/釋放等?？梢杂脕?lái)研究程序在哪里分配了大量?jī)?nèi)存，或者在什么地方產(chǎn)生碎片之類的和內(nèi)存管理相關(guān)的問(wèn)題。

perf kmem和perf lock實(shí)際上都是perf tracepoint的子類，等同于perf record -e kmem:*和perf record -e lock:*。

但是這些工具在內(nèi)部隊(duì)員是數(shù)據(jù)進(jìn)行了慧聰和分析，因此統(tǒng)計(jì)報(bào)表更具可讀性。

perf kmem record：抓取命令的內(nèi)核slab分配器事件

perf kmem stat：生成內(nèi)核slab分配器統(tǒng)計(jì)信息

選項(xiàng)：

--caller 顯示每個(gè)調(diào)用點(diǎn)統(tǒng)計(jì)信息 --alloc 顯示每次內(nèi)存分配事件 -s , --sort= Sort the output (default: frag,hit,bytes for slab and bytes,hit for page). Available sort keys are ptr, callsite, bytes, hit, pingpong, frag for slab and page, callsite, bytes, hit, order, migtype, gfp for page. This option should be preceded by one of the mode selection options - i.e. --slab, --page, --alloc and/or --caller. -l , 只顯示固定行數(shù) --raw-ip Print raw ip instead of symbol --slab 分析slab分配器事件 --page 分析頁(yè)分配事件 --live Show live page stat. The perf kmem shows total allocation stat by default, but this option shows live (currently allocated) pages instead. (This option works with --page option only)

3.9.2 perf kmem使用

sudo perf kmem record ls

sudo perf kmem stat只顯示概要統(tǒng)計(jì)信息：

SUMMARY (SLAB allocator) ======================== Total bytes requested: 368,589 Total bytes allocated: 369,424 Total bytes wasted on internal fragmentation: 835 Internal fragmentation: 0.226028% Cross CPU allocations: 0/2,256 sudo perf kmem --alloc --caller --slab stat顯示了更加詳細(xì)的分類信息： --------------------------------------------------------------------------------------------------------- Callsite | Total_alloc/Per | Total_req/Per | Hit | Ping-pong | Frag --------------------------------------------------------------------------------------------------------- proc_reg_open+32 | 64/64 | 40/40 | 1 | 0 | 37.500% seq_open+34 | 384/192 | 272/136 | 2 | 0 | 29.167% apparmor_file_alloc_security+5c | 608/32 | 456/24 | 19 | 1 | 25.000% ext4_readdir+8bd | 64/64 | 48/48 | 1 | 0 | 25.000% ext4_htree_store_dirent+3e | 896/68 | 770/59 | 13 | 0 | 14.062% load_elf_phdrs+64 | 1024/512 | 896/448 | 2 | 0 | 12.500% load_elf_binary+222 | 32/32 | 28/28 | 1 | 0 | 12.500% anon_vma_prepare+11b | 1280/80 | 1152/72 | 16 | 0 | 10.000% inotify_handle_event+75 | 73664/64 | 66758/58 | 1151 | 0 | 9.375% do_execveat_common.isra.33+e5 | 2048/256 | 1920/240 | 8 | 1 | 6.250% ... | ... | ... | ... | ... | ... --------------------------------------------------------------------------------------------------------- --------------------------------------------------------------------------------------------------------- Alloc Ptr | Total_alloc/Per | Total_req/Per | Hit | Ping-pong | Frag --------------------------------------------------------------------------------------------------------- 0xffff8800ca4d86c0 | 192/192 | 136/136 | 1 | 0 | 29.167% 0xffff8801ea05aa80 | 192/192 | 136/136 | 1 | 0 | 29.167% 0xffff8801f6ad6540 | 96/96 | 68/68 | 1 | 0 | 29.167% 0xffff8801f6ad6f00 | 96/96 | 68/68 | 1 | 0 | 29.167% 0xffff880214e65e80 | 96/32 | 72/24 | 3 | 0 | 25.000% 0xffff8801f45ddac0 | 64/64 | 48/48 | 1 | 0 | 25.000% 0xffff8800ac4093c0 | 32/32 | 24/24 | 1 | 1 | 25.000% 0xffff8800af5a4260 | 32/32 | 24/24 | 1 | 0 | 25.000% 0xffff880214e651e0 | 32/32 | 24/24 | 1 | 0 | 25.000% 0xffff880214e65220 | 32/32 | 24/24 | 1 | 0 | 25.000% 0xffff880214e654e0 | 32/32 | 24/24 | 1 | 0 | 25.000% --------------------------------------------------------------------------------------------------------- SUMMARY (SLAB allocator) ======================== Total bytes requested: 409,260 Total bytes allocated: 417,008 Total bytes wasted on internal fragmentation: 7,748 Internal fragmentation: 1.857998% Cross CPU allocations: 0/2,833

該報(bào)告有三個(gè)部分：根據(jù) Callsite 顯示的部分，所謂 Callsite 即內(nèi)核代碼中調(diào)用 kmalloc 和 kfree 的地方。

比如上圖中的函數(shù)proc_reg_open，Hit 欄為 1，表示該函數(shù)在 record 期間一共調(diào)用了 kmalloc 一次。

對(duì)于第一行 Total_alloc/Per 顯示為 1024/1024，第一個(gè)值 1024 表示函數(shù) proc_reg_open 總共分配的內(nèi)存大小，Per 表示平均值。

比較有趣的兩個(gè)參數(shù)是 Ping-pong 和 Frag。Frag 比較容易理解，即內(nèi)部碎片。雖然相對(duì)于 Buddy System，Slab 正是要解決內(nèi)部碎片問(wèn)題，但 slab 依然存在內(nèi)部碎片，比如一個(gè) cache 的大小為 1024，但需要分配的數(shù)據(jù)結(jié)構(gòu)大小為 1022，那么有 2 個(gè)字節(jié)成為碎片。Frag 即碎片的比例。

Ping-pong 是一種現(xiàn)象，在多 CPU 系統(tǒng)中，多個(gè) CPU 共享的內(nèi)存會(huì)出現(xiàn)”乒乓現(xiàn)象”。一個(gè) CPU 分配內(nèi)存，其他 CPU 可能訪問(wèn)該內(nèi)存對(duì)象，也可能最終由另外一個(gè) CPU 釋放該內(nèi)存對(duì)象。而在多 CPU 系統(tǒng)中，L1 cache 是 per CPU 的，CPU2 修改了內(nèi)存，那么其他的 CPU 的 cache 都必須更新，這對(duì)于性能是一個(gè)損失。Perf kmem 在 kfree 事件中判斷 CPU 號(hào)，如果和 kmalloc 時(shí)的不同，則視為一次 ping-pong，理想的情況下 ping-pong 越小越好。Ibm developerworks 上有一篇講述 oprofile 的文章，其中關(guān)于 cache 的調(diào)優(yōu)可以作為很好的參考資料。

Callsite：內(nèi)核代碼中調(diào)用kmalloc和kfree的地方。

Total_alloc/Per：總共分配的內(nèi)存大小，平均每次分配的內(nèi)存大小。

Total_req/Per：總共請(qǐng)求的內(nèi)存大小，平均每次請(qǐng)求的內(nèi)存大小。

Hit：調(diào)用的次數(shù)。

Ping-pong：kmalloc和kfree不被同一個(gè)CPU執(zhí)行時(shí)的次數(shù)，這會(huì)導(dǎo)致cache效率降低。

Frag：碎片所占的百分比，碎片 = 分配的內(nèi)存 - 請(qǐng)求的內(nèi)存，這部分是浪費(fèi)的。

有使用--alloc選項(xiàng)，還會(huì)看到Alloc Ptr，即所分配內(nèi)存的地址。

后面則有根據(jù)被調(diào)用地點(diǎn)的顯示方式的部分。

最后一個(gè)部分是匯總數(shù)據(jù)，顯示總的分配的內(nèi)存和碎片情況，Cross CPU allocation 即 ping-pong 的匯總。

要分析--page事件，需要在record的時(shí)候加上--page選項(xiàng)。sudo perf kmem record --page ls，使用sudo perf kmem stat --page查看結(jié)果：

0xee318 [0x8]: failed to process type: 68 error during process events: -22

3.10 perf sched

perf sched專門(mén)用于跟蹤/測(cè)量調(diào)度器，包括延時(shí)等。 perf sched record ：錄制測(cè)試過(guò)程中的調(diào)度事件 perf sched latency：報(bào)告線程調(diào)度延時(shí)和其他調(diào)度相關(guān)屬性 perf sched script：查看執(zhí)行過(guò)程中詳細(xì)的trace信息 perf sched replay：回放perf sched record錄制的執(zhí)行過(guò)程 perf sched map:用字符表示打印上下文切換 執(zhí)行sudo perf sched record ls后，通過(guò)不同方式查看結(jié)果。

sudo perf sched latency，可以看到ls進(jìn)程的Average delay/Maximum delay時(shí)間。各個(gè) column 的含義如下： Task: 進(jìn)程的名字和 pid Runtime: 實(shí)際運(yùn)行時(shí)間 Switches: 進(jìn)程切換的次數(shù) Average delay: 平均的調(diào)度延遲 Maximum delay: 最大延遲

這里最值得人們關(guān)注的是 Maximum delay，一般從這里可以看到對(duì)交互性影響最大的特性：調(diào)度延遲，如果調(diào)度延遲比較大，那么用戶就會(huì)感受到視頻或者音頻斷斷續(xù)續(xù)的。

----------------------------------------------------------------------------------------------------------------- Task | Runtime ms | Switches | Average delay ms | Maximum delay ms | Maximum delay at | ----------------------------------------------------------------------------------------------------------------- /usr/bin/termin:2511 | 0.163 ms | 1 | avg: 0.019 ms | max: 0.019 ms | max at: 5398.723467 s ls:7806 | 1.175 ms | 1 | avg: 0.017 ms | max: 0.017 ms | max at: 5398.722333 s kworker/u12:3:7064 | 0.029 ms | 1 | avg: 0.011 ms | max: 0.011 ms | max at: 5398.723434 s migration/4:27 | 0.000 ms | 1 | avg: 0.007 ms | max: 0.007 ms | max at: 5398.722575 s perf:7801 | 1.256 ms | 1 | avg: 0.002 ms | max: 0.002 ms | max at: 5398.723509 s ----------------------------------------------------------------------------------------------------------------- TOTAL: | 2.623 ms | 5 | ---------------------------------------------------

sudo perf sched script能看到更詳細(xì)的sched信息，包括sched_wakeup/sched_switch等等。每一列的含義依次是：進(jìn)程名/pid/CPU ID/時(shí)間戳。

perf 7801 [002] 5398.722314: sched:sched_stat_sleep: comm=perf pid=7806 delay=110095391 [ns] perf 7801 [002] 5398.722316: sched:sched_wakeup: comm=perf pid=7806 prio=120 target_cpu=004 swapper 0 [004] 5398.722328: sched:sched_stat_wait: comm=perf pid=7806 delay=0 [ns] swapper 0 [004] 5398.722333: sched:sched_switch: prev_comm=swapper/4 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=7806 next_prio=120 perf 7801 [002] 5398.722363: sched:sched_stat_runtime: comm=perf pid=7801 runtime=1255788 [ns] vruntime=3027478102 [ns] perf 7801 [002] 5398.722364: sched:sched_switch: prev_comm=perf prev_pid=7801 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120 perf 7806 [004] 5398.722568: sched:sched_wakeup: comm=migration/4 pid=27 prio=0 target_cpu=004 perf 7806 [004] 5398.722571: sched:sched_stat_runtime: comm=perf pid=7806 runtime=254732 [ns] vruntime=1979611107 [ns] perf 7806 [004] 5398.722575: sched:sched_switch: prev_comm=perf prev_pid=7806 prev_prio=120 prev_state=R+ ==> next_comm=migration/4 next_pid=27 next_prio=0 migration/4 27 [004] 5398.722582: sched:sched_stat_wait: comm=perf pid=7806 delay=13914 [ns] migration/4 27 [004] 5398.722586: sched:sched_migrate_task: comm=perf pid=7806 prio=120 orig_cpu=4 dest_cpu=2 swapper 0 [002] 5398.722595: sched:sched_stat_wait: comm=perf pid=7806 delay=0 [ns] swapper 0 [002] 5398.722596: sched:sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=7806 next_prio=120 migration/4 27 [004] 5398.722611: sched:sched_switch: prev_comm=migration/4 prev_pid=27 prev_prio=0 prev_state=S ==> next_comm=swapper/4 next_pid=0 next_prio=120 ls 7806 [002] 5398.723421: sched:sched_stat_sleep: comm=kworker/u12:3 pid=7064 delay=1226675 [ns] ls 7806 [002] 5398.723423: sched:sched_wakeup: comm=kworker/u12:3 pid=7064 prio=120 target_cpu=003 swapper 0 [003] 5398.723432: sched:sched_stat_wait: comm=kworker/u12:3 pid=7064 delay=0 [ns] swapper 0 [003] 5398.723434: sched:sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kworker/u12:3 next_pid=7064 next_prio=120 kworker/u12:3 7064 [003] 5398.723441: sched:sched_stat_sleep: comm=/usr/bin/termin pid=2511 delay=80833386 [ns] kworker/u12:3 7064 [003] 5398.723447: sched:sched_wakeup: comm=/usr/bin/termin pid=2511 prio=120 target_cpu=004 kworker/u12:3 7064 [003] 5398.723449: sched:sched_stat_runtime: comm=kworker/u12:3 pid=7064 runtime=29315 [ns] vruntime=846439549943 [ns] kworker/u12:3 7064 [003] 5398.723451: sched:sched_switch: prev_comm=kworker/u12:3 prev_pid=7064 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120 swapper 0 [004] 5398.723462: sched:sched_stat_wait: comm=/usr/bin/termin pid=2511 delay=0 [ns] swapper 0 [004] 5398.723466: sched:sched_switch: prev_comm=swapper/4 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=/usr/bin/termin next_pid=2511 next_prio=120 ls 7806 [002] 5398.723503: sched:sched_migrate_task: comm=perf pid=7801 prio=120 orig_cpu=2 dest_cpu=3 ls 7806 [002] 5398.723505: sched:sched_stat_sleep: comm=perf pid=7801 delay=1142537 [ns] ls 7806 [002] 5398.723506: sched:sched_wakeup: comm=perf pid=7801 prio=120 target_cpu=003 ls 7806 [002] 5398.723508: sched:sched_stat_runtime: comm=ls pid=7806 runtime=920005 [ns] vruntime=3028398107 [ns] swapper 0 [003] 5398.723508: sched:sched_stat_wait: comm=perf pid=7801 delay=0 [ns] swapper 0 [003] 5398.723508: sched:sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=7801 next_prio=120 ls 7806 [002] 5398.723510: sched:sched_switch: prev_comm=ls prev_pid=7806 prev_prio=120 prev_state=x ==> next_comm=swapper/2 next_pid=0 next_prio=120 /usr/bin/termin 2511 [004] 5398.723605: sched:sched_stat_runtime: comm=/usr/bin/termin pid=2511 runtime=162720 [ns] vruntime=191386139371 [ns] /usr/bin/termin 2511 [004] 5398.723611: sched:sched_switch: prev_comm=/usr/bin/termin prev_pid=2511 prev_prio=120 prev_state=S ==> next_comm=swapper/4 next_pid=0 next_prio=120

sudo perf sched map的好處在于提供了一個(gè)的總的視圖，將成百上千的調(diào)度事件進(jìn)行總結(jié)，顯示了系統(tǒng)任務(wù)在 CPU 之間的分布，假如有不好的調(diào)度遷移，比如一個(gè)任務(wù)沒(méi)有被及時(shí)遷移到 idle 的 CPU 卻被遷移到其他忙碌的 CPU，類似這種調(diào)度器的問(wèn)題可以從 map 的報(bào)告中一眼看出來(lái)。

星號(hào)表示調(diào)度事件發(fā)生所在的 CPU。

點(diǎn)號(hào)表示該 CPU 正在 IDLE。

 *A0 5398.722333 secs A0 => perf:7806 *. A0 5398.722365 secs . => swapper:0 . *B0 5398.722575 secs B0 => migration/4:27 *A0 B0 5398.722597 secs A0 *. 5398.722611 secs A0 *C0 . 5398.723434 secs C0 => kworker/u12:3:7064 A0 *. . 5398.723451 secs A0 . *D0 5398.723467 secs D0 => /usr/bin/termin:2511 A0 *E0 D0 5398.723509 secs E0 => perf:7801 *. E0 D0 5398.723510 secs . E0 *. 5398.723612 secs

perf sched replay 這個(gè)工具更是專門(mén)為調(diào)度器開(kāi)發(fā)人員所設(shè)計(jì)，它試圖重放 perf.data 文件中所記錄的調(diào)度場(chǎng)景。很多情況下，一般用戶假如發(fā)現(xiàn)調(diào)度器的奇怪行為，他們也無(wú)法準(zhǔn)確說(shuō)明發(fā)生該情形的場(chǎng)景，或者一些測(cè)試場(chǎng)景不容易再次重現(xiàn)，或者僅僅是出于“偷懶”的目的，使用 perf replay，perf 將模擬 perf.data 中的場(chǎng)景，無(wú)需開(kāi)發(fā)人員花費(fèi)很多的時(shí)間去重現(xiàn)過(guò)去，這尤其利于調(diào)試過(guò)程，因?yàn)樾枰欢?，再而三地重?fù)新的修改是否能改善原始的調(diào)度場(chǎng)景所發(fā)現(xiàn)的問(wèn)題。

run measurement overhead: 166 nsecs sleep measurement overhead: 52177 nsecs the run test took 999975 nsecs the sleep test took 1064623 nsecs nr_run_events: 11 nr_sleep_events: 581 nr_wakeup_events: 5 task 0 ( swapper: 0), nr_events: 11 task 1 ( swapper: 1), nr_events: 1 task 2 ( swapper: 2), nr_events: 1 task 3 ( kthreadd: 3), nr_events: 1 ... task 563 ( kthreadd: 7509), nr_events: 1 task 564 ( bash: 7751), nr_events: 1 task 565 ( man: 7762), nr_events: 1 task 566 ( kthreadd: 7789), nr_events: 1 task 567 ( bash: 7800), nr_events: 1 task 568 ( sudo: 7801), nr_events: 4 task 569 ( perf: 7806), nr_events: 8 ------------------------------------------------------------ #1 : 25.887, ravg: 25.89, cpu: 1919.68 / 1919.68 #2 : 27.994, ravg: 26.10, cpu: 2887.76 / 2016.49 #3 : 26.403, ravg: 26.13, cpu: 2976.09 / 2112.45 #4 : 29.400, ravg: 26.46, cpu: 1015.01 / 2002.70 #5 : 26.750, ravg: 26.49, cpu: 2942.80 / 2096.71 #6 : 27.647, ravg: 26.60, cpu: 3087.37 / 2195.78 #7 : 31.405, ravg: 27.08, cpu: 2762.43 / 2252.44 #8 : 23.770, ravg: 26.75, cpu: 2172.55 / 2244.45 #9 : 26.952, ravg: 26.77, cpu: 2794.93 / 2299.50 #10 : 30.904, ravg: 27.18, cpu: 973.26 / 2166.88

3.11 perf probe

Need to find vmlinux XXXXXXXXXXXXXXXXXX

可以自定義探測(cè)點(diǎn)。

Define new dynamic tracepoints.

?

使用例子

(1) Display which lines in schedule() can be probed # perf probe --line schedule 前面有行號(hào)的可以探測(cè)，沒(méi)有行號(hào)的就不行了。 (2) Add a probe on schedule() function 12th line. # perf probe -a schedule:12 在schedule函數(shù)的12處增加一個(gè)探測(cè)點(diǎn)。

3.14 perf trace

perf trace類似于strace，但增加了其他系統(tǒng)事件的分析，比如pagefaults、task lifetime事件、scheduling事件等。

?

下面的命令可以查看系統(tǒng)中已經(jīng)安裝的腳本：

# perf trace -l List of available trace scripts: syscall-counts [comm] system-wide syscall counts syscall-counts-by-pid [comm] system-wide syscall counts, by pid failed-syscalls-by-pid [comm] system-wide failed syscalls, by pid 

比如 failed-syscalls 腳本，執(zhí)行的效果如下：

# perf trace record failed-syscalls ^C[ perf record: Woken up 11 times to write data ] [ perf record: Captured and wrote 1.939 MB perf.data (~84709 samples) ] perf trace report failed-syscalls perf trace started with Perl script \ /root/libexec/perf-core/scripts/perl/failed-syscalls.pl failed syscalls, by comm: comm # errors -------------------- ---------- firefox 1721 claws-mail 149 konsole 99 X 77 emacs 56 [...] failed syscalls, by syscall: syscall # errors ------------------------------ ---------- sys_read 2042 sys_futex 130 sys_mmap_pgoff 71 sys_access 33 sys_stat64 5 sys_inotify_add_watch 4 [...]

該報(bào)表分別按進(jìn)程和按系統(tǒng)調(diào)用顯示失敗的次數(shù)。非常簡(jiǎn)單明了，而如果通過(guò)普通的 perf record 加 perf report 命令，則需要自己手工或者編寫(xiě)腳本來(lái)統(tǒng)計(jì)這些數(shù)字。

4. perf擴(kuò)展應(yīng)用

FlameGraph是

1.抓取perf信息并轉(zhuǎn)換

perf record -F 99 -a -g -- sleep 60 perf script > out.perf ./stackcollapse-perf.pl out.perf > out.folded ./flamegraph.pl out.kern_folded > kernel.svg