作者| 勿非
一、入門篇
1.資源角度
USE
產品跑在系統的各種資源上面, 從系統資源的角度入門性能分析是個不錯的選擇, 我們以業界知名大牛Brendan Gregg的USE方法開始, USE特點就是簡單有效適合入門, 用Brendan的話描述USE的效果：
I find it solves about 80% of server issues with 5% of the effort.
USE從系統資源的角度, 包括但不限于CPU, 內存, 磁盤, 網絡等, 關注以下3個方面：
- Utilization (U): as a percent over a time interval. eg, "one disk is running at 90% utilization". 大多數情況可以合理推測利用率高可能會影響性能。
- Saturation (S): as a queue length. eg, "the CPUs have an average run queue length of four". 資源競爭的激烈程度。
- Errors (E). scalar counts. eg, "this network interface has had fifty late collisions". Errors相對直觀。
CPU
對于CPU, 主要關注以下指標:
- Utilization. CPU的利用率。
- Saturation. 可以是load average, runqueue length, sched latency等。
CPU利用率用top看下：
top - 17:13:49 up 83 days, 23:10, 1 user, load average: 433.52, 422.54, 438.70
Tasks: 2765 total, 23 running, 1621 sleeping, 0 stopped, 34 zombie
%Cpu(s): 23.4 us, 9.5 sy, 0.0 ni, 65.5 id, 0.7 wa, 0.0 hi, 1.0 si, 0.0 st
CPU利用率拆分成了更細粒度的幾部分：
- us, sys, ni - 對應un-niced user, kernel, niced user的CPU利用率。
- id, wa - 對應到idle, io wait的比例, io wait本質上也是一種idle, 區別在于對應cpu上有等待io的任務。
- hi, si - 對應hardirq, softirq的比例。
- st - 因為超賣等原因, hypervisor從該vm偷走的時間 (todo: docker)。
繼續看load average, 3個數值分別對應到系統1/5/15分鐘內的系統平均load, load是個比較模糊的概念, 可以簡單認為是對資源有需求的任務數, 包括on cpu, runnable的任務, 也包括等待IO及任意D狀態的任務. load使用采樣的方式, 每隔5秒采樣一樣, 越近的采樣權重越大, 這樣從1/5/15的趨勢可以看出系統壓力的變化。
load average: 433.52, 422.54, 438.70
在這臺128個CPU的機器上, loadavg看起來有些偏高, 但是具體影響目前不得而知, 性能低是相對具體目標而言的, load高只是現象, 它可能相關也可能無關, 但至少是值得注意的。
再看下dstat關于任務狀態的統計：
- run - 對應到/proc/stat里面的procs_running, 也就是runnable任務數。
- blk - 對應到/proc/stat里面的procs_blocked, 阻塞在I/O的任務數。
實際上和loadavg沒有本質區別, 只是load模糊了runnable和D狀態, 同時load使用1/5/15分鐘的力度, 而dstat可以使用更細粒度, 如果只看某一時間點用load, 如果要觀察長時間的變化使用dstat (/proc/stat)。
#dstat -tp
----system---- ---procs---
time |run blk new
07-03 17:56:50|204 1.0 202
07-03 17:56:51|212 0 238
07-03 17:56:52|346 1.0 266
07-03 17:56:53|279 5.0 262
07-03 17:56:54|435 7.0 177
07-03 17:56:55|442 3.0 251
07-03 17:56:56|792 8.0 419
07-03 17:56:57|504 16 152
07-03 17:56:58|547 3.0 156
07-03 17:56:59|606 2.0 212
07-03 17:57:00|770 0 186
內存
這里主要關注內存容量方面, 不關注訪存的性能。
- Utilization. 內存利用率。
- Saturation. 這里主要考察內存回收算法的效率。
簡單的內存利用率用free命令：
- total - MemTotal + SwapTotal, 一般來說MemTotal會略小于真實的物理內存。
- free - 未使用的內存. Linux傾向于緩存更多頁面以提高性能, 所以不能簡通過free來判斷內存是否不足。
- buff/cache - 系統緩存, 一般不需要嚴格區分buffer和cache。
- available - 估計的可用物理內存大小。
- used - 等于total - free - buffers - cache。
- Swap - 該機器上未配置。
#free -g
total used free shared buff/cache available
Mem: 503 193 7 2 301 301
Swap: 0 0 0
更詳細的信息可以直接去讀/proc/meminfo：
#cat /proc/meminfo
MemTotal: 527624224 kB
MemFree: 8177852 kB
MemAvailable: 316023388 kB
Buffers: 23920716 kB
Cached: 275403332 kB
SwapCached: 0 kB
Active: 59079772 kB
Inactive: 431064908 kB
Active(anon): 1593580 kB
Inactive(anon): 191649352 kB
Active(file): 57486192 kB
Inactive(file): 239415556 kB
Unevictable: 249700 kB
Mlocked: 249700 kB
SwapTotal: 0 kB
SwapFree: 0 kB
[...]
再來看下內存回收相關的信息, sar的數據主要從/proc/vmstat采集, 主要關注：
- pgscank/pgscand - 分別對應kswapd/direct內存回收時掃描的page數。
- pgsteal - 回收的page數。
- %vmeff - pgsteal/(pgscank+pgscand)
要理解這些數據的具體含義, 需要對內存管理算法有一定了解, 比如這里的pgscan/pgsteal只是針對inactive list而言的, 在內存回收的時候可能還需要先把頁面從active list搬到inactive list等. 如果這里有異常, 我們可以先把這當成入口, 再慢慢深入, 具體到這里的%vmeff, 最好情況就是每個掃描的page都能回收, 也就是vmeff越高越好。
#sar -B 1
11:00:16 AM pgscank/s pgscand/s pgsteal/s %vmeff
11:00:17 AM 0.00 0.00 3591.00 0.00
11:00:18 AM 0.00 0.00 10313.00 0.00
11:00:19 AM 0.00 0.00 8452.00 0.00
I/O
存儲I/O的USE模型：
- Utilization. 存儲設備的利用率, 單位時間內設備在處理I/O請求的時間。
- Saturation. 隊列長度。
我們一般關注這些部分：
- %util - 利用率. 注意即使達到100%的util, 也不代表設備沒有性能余量了, 特別地現在的SSD盤內部都支持并發. 打個比方, 一家旅館有10間房, 每天只要有1個房間入住, util就是100%。
- svctm - 新版iostat已經刪掉。
- await/r_await/w_await - I/O延遲, 包括排隊時間。
- avgrq-sz - 平均request size, 請求處理時間和大小有一定關系, 不一定線性。
- argqu-sz - 評估queue size, 可以用來判斷是否有積壓。
- rMB/s, wMB/s, r/s, w/s - 基本語義。
資源粒度
當我們判斷資源是否是瓶頸的時候, 只看系統級別的資源是不夠的, 比如可以用htop看下每個CPU的利用率, 目標任務運行在不同CPU上的性能可能相差很大。
內存也有類似情況, 運行numastat -m。
Node 0 Node 1 Node 2 Node 3
--------------- --------------- --------------- ---------------
MemTotal 31511.92 32255.18 32255.18 32255.18
MemFree 2738.79 131.89 806.50 10352.02
MemUsed 28773.12 32123.29 31448.69 21903.16
Active 7580.58 419.80 9597.45 5780.64
Inactive 17081.27 26844.28 19806.99 13504.79
Active(anon) 6.63 0.93 2.08 5.64
Inactive(anon) 12635.75 25560.53 12754.29 9053.80
Active(file) 7573.95 418.87 9595.37 5775.00
Inactive(file) 4445.52 1283.75 7052.70 4450.98
系統不一定就是物理機, 如果產品跑在cgroup, 那么這個cgroup是更需要關注的系統, 比如在空閑系統上執行如下命令：
#mkdir /sys/fs/cgroup/cpuset/overloaded
#echo 0-1 > /sys/fs/cgroup/cpuset/cpuset.cpus
#echo 0 > /sys/fs/cgroup/cpuset/cpuset.mems
#echo $$
#for i in {0..1023}; do /tmp/busy & done
此時從物理機級別看, 系統的load很高, 但是因為cpuset的限制, 競爭約束在cpu 0和1上, 對運行在其他cpu上的產品影響并不大。
#uptime
14:10:54 up 6 days, 18:52, 10 users, load average: 920.92, 411.61, 166.95
2.應用角度
系統資源和應用的性能可能會有某種關聯, 但是也可以更直接地從應用的角度出發定位問題：
- 應用能使用多少資源, 而不是系統提供了多少資源, 這里面可能會有gap, 系統是個模糊的概念, 而應用本身卻相對具體. 以上面cpuset為例, 物理機是個系統cpuset管理的資源也可以成為系統, 但是應用在cpuset里面還是外面是確定的。
- 應用對資源的需求, 即使系統資源再多, 應用用不上性能也上不去, 也就是系統可能沒問題, 而是應用本身的原因。
以下面的myserv為例, 它的4個線程%cpu都達到了100, 這個時候再去分析整個系統的load什么用處不大, 系統有再多的空閑cpu對myserv來說已經沒有意義。
#pidstat -p `pgrep myserv` -t 1
15:47:05 UID TGID TID %usr %system %guest %CPU CPU Command
15:47:06 0 71942 - 415.00 0.00 0.00 415.00 22 myserv
15:47:06 0 - 71942 0.00 0.00 0.00 0.00 22 |__myserv
...
15:47:06 0 - 72079 7.00 94.00 0.00 101.00 21 |__myserv
15:47:06 0 - 72080 10.00 90.00 0.00 100.00 19 |__myserv
15:47:06 0 - 72081 9.00 91.00 0.00 100.00 35 |__myserv
15:47:06 0 - 72082 5.00 95.00 0.00 100.00 29 |__myserv
3.常用命令
基本命令
基本命令一般用來讀取內核中記錄的各種統計信息, 特別是/proc下面的各種文件, 這里簡單列舉部分：
- top - 提供了交互模式和batch模式, 不帶參數進入交互模式, 按下h鍵可以看到各種功能。
- ps - 提供了各種參數查看系統中任務的狀態, 比如ps aux或者ps -eLf, 很多參數可以在需要的時候查看手冊。
- free - 內存信息。
- iostat - I/O性能。
- pidstat - 查看進程相關的信息, 上面已經介紹過。
- mpstat - 可以查看單獨cpu的利用率, softirq, hardirq個數等。
- vmstat - 可以查看虛擬內存及各種系統信息。
- netstat - 網絡相關。
- dstat - 可以查看cpu/disk/mem/net等各種信息, 這些stat命令哪個方便用哪個。
- htop - 上面介紹過。
- irqstat - 方便觀察中斷信息。
- sar/tsar/ssar - 收集和查看系統運行的各種歷史信息, 也提供實時模式。
這里舉個ps的例子, 我們監控mysqld服務, 當該進程使用的內存超過系統內存70%的時候, 通過gdb調用jemalloc的malloc_stats_print函數來分析可能的內存泄漏。
largest=70
while :; do
mem=$(ps -p `pidof mysqld` -o %mem | tail -1)
imem=$(printf %.0f $mem)
if [ $imem -gt $largest ]; then
echo 'p malloc_stats_print(0,0,0)' | gdb --quiet -nx -p `pidof mysqld`
fi
sleep 10
done
perf
perf是性能分析的必備工具, 它最核心的能力是能訪問硬件上的Performance Monitor Unit (PMU), 對分析CPU bound的問題很有幫助, 當然perf也支持各種軟件event. perf的主要能力包括：
- 通過采樣發現程序熱點。
- 通過硬件PMU深入分析問題的根源, 特別是配合硬件上的優化。
perf list可以列出支持的event, 我們可以通過perf來獲取cache misses, cycles等等。
#perf list | grep Hardware
branch-misses [Hardware event]
bus-cycles [Hardware event]
cache-misses [Hardware event]
cache-references [Hardware event]
cpu-cycles OR cycles [Hardware event]
instructions [Hardware event]
L1-dcache-load-misses [Hardware cache event]
L1-dcache-loads [Hardware cache event]
L1-dcache-store-misses [Hardware cache event]
L1-dcache-stores [Hardware cache event]
L1-icache-load-misses [Hardware cache event]
L1-icache-loads [Hardware cache event]
branch-load-misses [Hardware cache event]
branch-loads [Hardware cache event]
dTLB-load-misses [Hardware cache event]
iTLB-load-misses [Hardware cache event]
mem:<addr>[/len][:access] [Hardware breakpoint]
perf使用的時候一般會傳入以下參數：
- 通過-e指定感興趣的一個或多個event。
- 指定采樣的范圍, 比如進程級別 (-p), 線程級別 (-t), cpu級別 (-C), 系統級別 (-a)。
這里使用默認的event看下進程31925的執行情況. 一個比較重要的信息是insns per cycle (IPC), 也就是每個cycle能執行多少指令, 其他pmu event像cache misses, branch misses如果有問題最終都會反映到IPC上. 雖然沒有一個明確的標準, 但是下面0.09的IPC是比較低的, 有必要繼續深入。
#perf stat -p 31925 sleep 1
Performance counter stats for process id '31925':
2184.986720 task-clock (msec) # 2.180 CPUs utilized
3,210 context-switches # 0.001 M/sec
345 cpu-migrations # 0.158 K/sec
0 page-faults # 0.000 K/sec
4,311,798,055 cycles # 1.973 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
409,465,681 instructions # 0.09 insns per cycle
<not supported> branches
8,680,257 branch-misses # 0.00% of all branches
1.002506001 seconds time elapsed
除了stat外, perf另一個可能更常用的方式是采樣來確定程序的熱點, 現在有如下程序：
void busy(long us) {
struct timeval tv1, tv2;
long delta = 0;
gettimeofday(&tv1, NULL);
do {
gettimeofday(&tv2, NULL);
delta = (tv2.tv_sec - tv1.tv_sec) * 1000000 + tv2.tv_usec - tv1.tv_usec;
} while (delta < us);
}
void A() { busy(2000); }
void B() { busy(8000); }
int main() {
while (1) {
A(); B();
}
return 0;
}
函數A和B執行時間的比例, perf的采樣結果和我們期望的2:8基本一致。
#perf record -g -e cycles ./a.out
#perf report
Samples: 27K of event 'cycles', Event count (approx.): 14381317911
Children Self Command Shared Object Symbol
+ 99.99% 0.00% a.out [unknown] [.] 0x0000fffffb925137
+ 99.99% 0.00% a.out a.out [.] _start
+ 99.99% 0.00% a.out libc-2.17.so [.] __libc_start_main
+ 99.99% 0.00% a.out a.out [.] main
+ 99.06% 25.95% a.out a.out [.] busy
+ 79.98% 0.00% a.out a.out [.] B
- 71.31% 71.31% a.out [vdso] [.] __kernel_gettimeofday
__kernel_gettimeofday
- busy
+ 79.84% B
+ 20.16% A
+ 20.01% 0.00% a.out a.out [.] A
strace
trace相對于采樣最大的優勢在于精度, trace能抓住每次操作, 這給調試和理解帶來很大方便. strace專門用來trace系統調用。
strace通過捕獲所有的系統調用能快速幫助理解應用的某些行為, 這里使用strace來看下上面提到的perf-record的實現, 很容易發現系統調用perf_event_open以及它的參數, 因為有128個cpu, 針對每個cpu都會調用一次該系統調用。
#strace -v perf record -g -e cycles ./a.out
perf_event_open({type=PERF_TYPE_HARDWARE, size=PERF_ATTR_SIZE_VER5, config=PERF_COUNT_HW_CPU_CYCLES, sample_freq=4000, sample_type=PERF_SAMPLE_IP|PERF_SAMPLE_TID|PERF_SAMPLE_TIME|PERF_SAMPLE_CALLCHAIN|PERF_SAMPLE_PERIOD, read_format=0, disabled=1, inherit=1, pinned=0, exclusive=0, exclusive_user=0, exclude_kernel=0, exclude_hv=0, exclude_idle=0, mmap=1, comm=1, freq=1, inherit_stat=0, enable_on_exec=1, task=1, watermark=0, precise_ip=0 /* arbitrary skid */, mmap_data=0, sample_id_all=1, exclude_host=0, exclude_guest=1, exclude_callchain_kernel=0, exclude_callchain_user=0, mmap2=1, comm_exec=1, use_clockid=0, context_switch=0, write_backward=0, namespaces=0, wakeup_events=0, config1=0, config2=0, sample_regs_user=0, sample_regs_intr=0, aux_watermark=0, sample_max_stack=0}, 51876, 25, -1, PERF_FLAG_FD_CLOEXEC) = 30
blktrace
iostat因為粒度太粗有的時候并不能很好地定位問題, blktrace通過跟蹤每個I/O, 并在I/O的關鍵路徑打樁, 可以獲得更精確的信息, 從而幫忙分析問題. blktrace封裝了幾個命令:
- blktrace: 收集。
- blkparse: 處理。
- btt: 強大的分析工具。
- btrace: blktrace/blkparse的一個簡單封裝, 相當于blktrace -d /dev/sda -o - | blkparse -i 。
簡單看下blktrace的輸出, 里面記錄了I/O路徑上的關鍵信息, 特別地：
- 時間戳, 性能分析的關鍵信息之一。
- event, 第6列, 對應到I/O路徑上的關鍵點, 具體對應關系可以查找相應手冊或源碼, 理解這些關鍵點是調試I/O性能的必要技能。
- I/O sector. I/O請求對應的扇區和大小。
$ sudo btrace /dev/sda
8,0 0 1 0.000000000 1024 A WS 302266328 + 8 <- (8,5) 79435736
8,0 0 2 0.000001654 1024 Q WS 302266328 + 8 [jbd2/sda5-8]
8,0 0 3 0.000010042 1024 G WS 302266328 + 8 [jbd2/sda5-8]
8,0 0 4 0.000011605 1024 P N [jbd2/sda5-8]
8,0 0 5 0.000014993 1024 I WS 302266328 + 8 [jbd2/sda5-8]
8,0 0 0 0.000018026 0 m N cfq1024SN / insert_request
8,0 0 0 0.000019598 0 m N cfq1024SN / add_to_rr
8,0 0 6 0.000022546 1024 U N [jbd2/sda5-8] 1
這是btt的一個輸出, 可以看到S2G的個數和延遲, 正常情況不應該出現這個問題, 這樣就找到了一條可以深入的線索。
$ sudo blktrace -d /dev/sdb -w 5
$ blkparse sdb -d sdb.bin
$ btt -i sdb.bin
==================== All Devices ====================
ALL MIN AVG MAX N
--------------- ------------- ------------- ------------- -----------
Q2Q 0.000000001 0.000014397 0.008275391 347303
Q2G 0.000000499 0.000071615 0.010518692 347298
S2G 0.000128160 0.002107990 0.010517875 11512
G2I 0.000000600 0.000001570 0.000040010 347298
I2D 0.000000395 0.000000929 0.000003743 347298
D2C 0.000116199 0.000144157 0.008443855 347288
Q2C 0.000118211 0.000218273 0.010678657 347288
==================== Device Overhead ====================
DEV | Q2G G2I Q2M I2D D2C
---------- | --------- --------- --------- --------- ---------
( 8, 16) | 32.8106% 0.7191% 0.0000% 0.4256% 66.0447%
---------- | --------- --------- --------- --------- ---------
Overall | 32.8106% 0.7191% 0.0000% 0.4256% 66.0447%
二、進階篇
1.大學教材
通過教程能夠系統地了解一門課的全貌, 網上搜到的大部分性能分析的教程都是基于Raj Jain的The Art of Computer Systems Performance Analysis, 這本書里面主要包括幾個部分：
- Part I: AN OVERVIEW OF PERFORMANCE EVALUATION.
- Part II: MEASUREMENT TECHNIQUES AND TOOLS.
- Part III: PROBABILITY THEORY AND STATISTICS.
- Part IV: EXPERIMENTAL DESIGN AND ANALYSIS.
- Part V: SIMULATION.
- Part VI: QUEUEING MODELS.
書的重心放在performance analysis上面, 涉及較多概率和統計的計算, 另外rice大學的這個教程寫得挺不錯[1]。
2.技術博客
- 參考文末[2]有時間可以都過一遍, 總的來說主要包括3個部分：
性能分析的方法集. 代表作 USE方法。
性能數據的搜集. 代表作 "工具大圖"。
性能數據的可視化. 代表作 火焰圖。
- 文末鏈接[3]
- 文末鏈接[4]
- 文末鏈接[5]
3.知識結構
系統性能分析在深度和廣度上都有要求, 對底層包括OS和硬件, 以及一些通用能力要做到足夠深, 對上層產品的理解又需要有足夠的廣度, 近一年在混合云親手摸過的產品估計不下二十款, 當然重點分析過的只有幾個。
操作系統
操作系統是系統分析的基礎, 不管是I/O, 內存, 網絡, 調度, docker等等都離不開操作系統, 操作系統知識可以從Understanding the Linux Kernel開始, 這本書雖然老了但不妨礙理解OS的基本概念, 慢慢做到能閱讀內核文檔和源碼。
在適配某款arm平臺的時候發現, 在numa off的情況下：
- ecs綁在socket 0上性能好；
- mysql綁在socket 1上性能好。
能確定的是, 該平臺跨socket性能訪問不管是latency還是throughput和本地訪問都有較大差距, 所以一個合理的方向是跨socket的內存訪問, 如果有類似x86 pcm的話會比較直接, 但是該平臺上缺少該類pmu來查看跨socket的信息, 我們嘗試從OS的角度來回答這個問題。
首先通過將內存壓測工具跑在不同的socket/node上, 發現numa off表現出了和numa on相同的性能特征, 和硬件產生確認該平臺numa off和on的實現在硬件上并沒有區別, 只是bios不傳遞numa信息給操作系統, 這樣是可以知道物理地址在哪個socket/node上的。
接下來只要確定ecs/mysql的物理內存位置, 就可以用于判斷性能和跨socket的相關性. Linux在用戶態可以通過pagemap將虛擬地址對應到物理地址, 只需要稍加修改tools/vm/page-types.c就能拿到進程對應的所有物理地址. 經確認, 確實ecs/mysql的性能和它們使用的物理內存的位置強相關。
最后要回答的是為什么ecs和mysql表現恰好相反, 注意到ecs使用hugepage而mysql使用normal page, 有如下假設, 具體代碼這里不再列出。
- 系統啟動的時候, 物理內存加到伙伴系統是先socket 0后socket 1。
- socket 1上的內存會被先分出來, 所以mysql分配的內存在socket 1. 特定集群的機器不會隨意跑其他進程。
- 在ecs的host上, 因為要分配的hugepage已經超過了socket 1上的所有內存, 所以后面分配的hugepage已經落在了socket 0。
- hugepage的分配是后進先出, 意味著ecs一開始分配到的hugepage在socket 0, 而該機器資源并沒全部用完, 測試用的幾個ecs內存全落在了socket 0上, 所以將ecs進程綁到socket 0的性能更好。
硬件知識
如果一直是x86架構, 事情會簡單很多, 一是x86的知識大家耳濡目染很久了, 多多少少都了解一些, 二是架構變化相對較小, 各種應用都適配較好, 需要調優的用例較少. 隨著各種新平臺的崛起, 它們性能各異, 對整個系統性能帶來的沖擊是巨大的, 這不是影響某個產品, 這影響的幾乎是所有產品. 最基本地, 我們要處理以下問題：
- 新的平臺上, 應用原有的很多假設被打破, 需要重新適配, 否則性能可能不及預期. 比如在Intel上面, 開關numa的性能差距不大，在其他平臺上可能就不一樣。
- 新的平臺要取代老的平臺, 就存在性能的比較. 由于平臺性能差異大并且差異點多，雖然speccpu之類的benchmark能一定程度反應平臺整體的計算性能, 但很多時候還需要結合不同場景分別進行性能調優。
- 不排除新平臺存在某種bug或者未知的feature, 都需要我們去摸索解決的辦法。
數據分析
在收集了大量數據后, 經過數據分析可以放大數據的價值
- 數據提取. 利用各種工具比如awk/sed/perl等腳本語言提取所需的數據。
- 數據抽象. 從不同角度加工數據, 識別異常, 比如單機/集群分別是什么表現, 統計哪些值。
- 可視化. 可視化是數據處理非常重要的能力, 一圖勝千言, 火焰圖就是最好的例子. 常用畫圖工具有gnuplot, excel等。
比如分析MapReduce任務在10臺機器的集群上的性能, 即使每臺機器都體現出一定的共性, 但是如果從集群角度看的話則更加明顯, 也很容易驗證這種共性。
換種顯示方式則更加明顯, 很容易知道在不同階段的表現, 比如正常Map和Reduce階段cpu利用率也只有80%, 這個是否符合預期, 另外在Map和Reduce切換的時候, 系統idle很明顯, 會不會是潛在優化點。
如果有對照的話, 可以直觀地看不到不同表現, 特別是巨大的長尾時間有進一步優化的空間。
Benchmarking
Benchmarking是獲取性能指標最基本的手段, 也是測試常用的方法, 每個領域幾乎都有自己的一套測試用例. 對于benchmarking, 首先需要知道它測的是什么. 以spec cpu2017為例, 它主要測試的是處理器, 內存子系統以及編譯器的性能, 那么在測試的時候我們除了關注CPU型號, 還要考慮內存大小插法型號, 以及編譯器及其參數等等, 在做性能比對時也能清楚它的使用范圍。
Benchmark的一個特點是可重復性, spec.org做得很好的一點是上面有大量公布的測試結果, 可以參考這些測試結果來驗證我們自己的測試方法參數是否合理. 如果想測試cpu2017, 第一件事就是先重做別人的測試, 直到能復現別人的數據, 這個過程可能會有很多收獲, 對benchmark也會有更多了解. 以intel 8160為例, 在硬件基本一致的情況下, 不經額外的配置自己環境cpu2017 integer rate只能跑到140, 而spec.org上面的測試用例能達到240, 性能逐步逼近240的過程, 也是深入理解cpu2017的過程。
關于性能數據, 首先想要強調的是有數據并不一定比沒數據強, 只有解釋過的數據才是有效數據, 沒解釋過的數據反而會引起不必要的誤判, 比如上面cpu2017的例子, 在做不同平臺性能對比的時候, 8160到底用140還是240呢, 得出的結論會十萬八千里. 再比如使用下面的命令測試某新平臺的內存延遲：
lat_mem_rd -P 1 -N 1 10240 512
測試出的延遲是7.4ns, 不加分析采用該結果就可能得出新平臺延遲太好的錯誤結論. 所以對待數據要足夠謹慎, 一般會有幾個階段：
- 在信任關系建立前, 對別人的數據保持謹慎. 一是有可能自己對這塊還沒有足夠理解, 二是需要測試報告提供足夠的信息供他人做判斷。
- 相信自己的數據. 必須相信自己, 但是選擇相信自己的數據, 是因為有過詳細合理的分析。
- 相信別人的數據. 信任鏈建立之后, 以及自己有了足夠理解后, 選擇相信。
4.更多工具
ftrace
想要快速理解代碼實現, 沒有什么比打印調用路徑更直接了. ftrace可以用來解決2個問題：
- 誰調用了我. 這個只要在執行對應函數的時候拿到對應的棧就可以, 多種工具可以實現;
- 我調用了誰. 這個是ftrace比較unique的功能。
為了方便我們使用ftrace的wrapper trace-cmd, 假設我們已經知道I/O路徑會經過generic_make_request, 為了查看完整的路徑我們可以這樣：
#trace-cmd record -p function --func-stack -l generic_make_request dd if=/dev/zero of=file bs=4k count=1 oflag=direct
通過report來查看就一目了然了：
#trace-cmd report
cpus=128
dd-11344 [104] 4148325.319997: function: generic_make_request
dd-11344 [104] 4148325.320002: kernel_stack: <stack trace>
=> ftrace_graph_call (ffff00000809849c)
=> generic_make_request (ffff000008445b80)
=> submit_bio (ffff000008445f00)
=> __blockdev_direct_IO (ffff00000835a0a8)
=> ext4_direct_IO_write (ffff000001615ff8)
=> ext4_direct_IO (ffff0000016164c4)
=> generic_file_direct_write (ffff00000825c4e0)
=> __generic_file_write_iter (ffff00000825c684)
=> ext4_file_write_iter (ffff0000016013b8)
=> __vfs_write (ffff00000830c308)
=> vfs_write (ffff00000830c564)
=> ksys_write (ffff00000830c884)
=> __arm64_sys_write (ffff00000830c918)
=> el0_svc_common (ffff000008095f38)
=> el0_svc_handler (ffff0000080960b0)
=> el0_svc (ffff000008084088)
現在如果我們想繼續深入generic_make_request, 使用function_graph plugin：
$ sudo trace-cmd record -p function_graph -g generic_make_request dd if=/dev/zero of=file bs=4k count=1 oflag=direct
這樣就可以拿到整個調用過程 (report結果稍微整理過)：
$ trace-cmd report
dd-22961 | generic_make_request() {
dd-22961 | generic_make_request_checks() {
dd-22961 0.080 us | _cond_resched();
dd-22961 | create_task_io_context() {
dd-22961 0.485 us | kmem_cache_alloc_node();
dd-22961 0.042 us | _raw_spin_lock();
dd-22961 0.039 us | _raw_spin_unlock();
dd-22961 1.820 us | }
dd-22961 | blk_throtl_bio() {
dd-22961 0.302 us | throtl_update_dispatch_stats();
dd-22961 1.748 us | }
dd-22961 6.110 us | }
dd-22961 | blk_queue_bio() {
dd-22961 0.491 us | blk_queue_split();
dd-22961 0.299 us | blk_queue_bounce();
dd-22961 0.200 us | bio_integrity_enabled();
dd-22961 0.183 us | blk_attempt_plug_merge();
dd-22961 0.042 us | _raw_spin_lock_irq();
dd-22961 | elv_merge() {
dd-22961 0.176 us | elv_rqhash_find.isra.9();
dd-22961 | deadline_merge() {
dd-22961 0.108 us | elv_rb_find();
dd-22961 0.852 us | }
dd-22961 2.229 us | }
dd-22961 | get_request() {
dd-22961 0.130 us | elv_may_queue();
dd-22961 | mempool_alloc() {
dd-22961 0.040 us | _cond_resched();
dd-22961 | mempool_alloc_slab() {
dd-22961 0.395 us | kmem_cache_alloc();
dd-22961 0.744 us | }
dd-22961 1.650 us | }
dd-22961 0.334 us | blk_rq_init();
dd-22961 0.055 us | elv_set_request();
dd-22961 4.565 us | }
dd-22961 | init_request_from_bio() {
dd-22961 | blk_rq_bio_prep() {
dd-22961 | blk_recount_segments() {
dd-22961 0.222 us | __blk_recalc_rq_segments();
dd-22961 0.653 us | }
dd-22961 1.141 us | }
dd-22961 1.620 us | }
dd-22961 | blk_account_io_start() {
dd-22961 0.137 us | disk_map_sector_rcu();
dd-22961 | part_round_stats() {
dd-22961 0.195 us | part_round_stats_single();
dd-22961 0.054 us | part_round_stats_single();
dd-22961 0.955 us | }
dd-22961 2.148 us | }
dd-22961 + 15.847 us | }
dd-22961 + 23.642 us | }
uftrace
uftrace在用戶態實現了一個類似ftrace的功能, 對需要快速理解用戶態的邏輯會有幫助, 但是需要加上-pg重新編譯源碼, 詳情見[6]。
#gcc -pg a.c
#uftrace ./a.out
# DURATION TID FUNCTION
[ 69439] | main() {
[ 69439] | A() {
0.160 us [ 69439] | busy();
1.080 us [ 69439] | } /* A */
[ 69439] | B() {
0.050 us [ 69439] | busy();
0.240 us [ 69439] | } /* B */
1.720 us [ 69439] | } /* main */
BPF
BPF (eBPF) 是這幾年的熱點, 通過BPF幾乎可以看清系統的各個角落, 給診斷帶來了極大的方便. BPF不是一個工具, BPF是生產工具的工具, BPF工具編寫是性能分析必須掌握的技能之一。
這里舉個使用BPF來分析QEMU I/O延遲的例子. 為了簡化問題, 先確保vm里面的塊設備只有fio在使用, fio控制設備只有一個并發I/O, 這樣我們在host上選擇2個觀察點：
- tracepoint:kvm:kvm_mmio. host捕獲guest mmio操作, guest里面最終通過寫該mmio發送請求給host;
- kprobe:kvm_set_msi. 因為guest里面vdb使用msi中斷, 中斷最終通過該函數注入;
因為host上有多個vm和虛擬盤需要區分, 使用以下信息捕獲并且只捕獲我們關注的這個設備：
- 只關注該qemu-kvm pid;
- vbd mmio對應的gpa, 這個可以在guest里面通過lspci獲得;
對于kvm_set_msi, 使用如下信息：
- struct kvm的userspace_pid, struct kvm對應的qemu-kvm進程;
- struct kvm_kernel_irq_routing_entry的msi.devid, 對應到pci設備id;
#include <linux/kvm_host.h>
BEGIN {
@qemu_pid = $1;
@mmio_start = 0xa000a00000;
@mmio_end = 0xa000a00000 + 16384;
@devid = 1536;
}
tracepoint:kvm:kvm_mmio /pid == @qemu_pid/ {
if (args->gpa >= @mmio_start && args->gpa < @mmio_end) {
@start = nsecs;
}
}
kprobe:kvm_set_msi {
$e = (struct kvm_kernel_irq_routing_entry *)arg0;
$kvm = (struct kvm *)arg1;
if (@start > 0 && $kvm->userspace_pid == @qemu_pid && $e->msi.devid == @devid) {
@dur = stats(nsecs - @start);
@start = 0;
}
}
interval:s:1 {
print(@dur); clear(@dur);
}
執行結果如下：
@dur: count 598, average 1606320, total 960579533
@dur: count 543, average 1785906, total 969747196
@dur: count 644, average 1495419, total 963049914
@dur: count 624, average 1546575, total 965062935
@dur: count 645, average 1495250, total 964436299
5.更深理解
很多技術需要反復去理解驗證, 每一次可能都有不同的收獲, 這里舉個loadavg的例子. 引用kernel/sched/loadavg.c最開始的一段注釋：
5 * This file contains the magic bits required to compute the global loadavg
6 * figure. Its a silly number but people think its important. We go through
7 * great pains to make it work on big machines and tickless kernels.
這里的silly我想說的是loadavg有一定的局限性, 總的來說loadavg是有一定語義和價值的, 畢竟它只用了3個數字描述了過去一段時間的"load", 反過來說如果loadavg is silly, 那么有沒有更好的選擇?
- 如果是實時觀察的話, vmstat/dstat輸出的runnable和I/O blocked的信息是種更好的選擇, 因為相對于loadavg每5秒的采樣。 vmstat可以做到粒度更細, 而且loadavg的算法某種程度可以理解為有損的。
- 如果是sar/tsar的話, 假設收集間隔是10min的話, loadavg因為能覆蓋更大的范圍, 確實比10min一個的數字包含更多的信息。 但我們需要思考它對調試的真正價值。
另外, 5秒鐘的采樣間隔是比較大的, 我們可以構造個測試用例執行了大量時間但跳過采樣。
- 獲取load采樣點的時間。
- 測試用例剛好跳過該采樣點。
查看calc_load_fold_active在cpu 0上的調用時間：
kprobe:calc_load_fold_active /cpu == 0/ {
printf("%ld\n", nsecs / 1000000000);
}
運行沒有輸出, 監控上一層函數：
#include "kernel/sched/sched.h"
kprobe:calc_global_load_tick /cpu == 0/ {
$rq = (struct rq *)arg0;
@[$rq->calc_load_update] = count();
}
interval:s:5 {
print(@); clear(@);
}
執行結果符合預期：
#./calc_load.bt -I /kernel-source
@[4465886482]: 61
@[4465887733]: 1189
@[4465887733]: 62
@[4465888984]: 1188
查看匯編發現這里代碼被優化, 但是剛好id_nr_invalid調用沒優化, 當然最方便的是能夠直接在函數偏移處直接打點:
kprobe:id_nr_invalid /cpu == 0/ {
printf("%ld\n", nsecs / 1000000000);
}
根據這個時間戳, 可以很容易跳過load的統計：
while :; do
sec=$(awk -F. '{print $1}' /proc/uptime)
rem=$((sec % 5))
if [ $rem -eq 2 ]; then # 1s after updating load
break;
fi
sleep 0.1
done
for i in {0..63}; do
./busy 3 & # run 3s
done
大量busy進程成功跳過load的統計, 可以設想像cron執行的任務也是有這個可能的. 雖然不能否認loadavg的價值, 但總的來說load有以下缺陷：
- 系統級別的統計, 和具體應用產生的聯系不夠直接。
- 使用采樣的方式并且采樣間隔 (5s) 較大, 有的場景不能真實反映系統。
- 統計的間隔較大(1/5/15分鐘), 不利于及時反映當時的情況。
- 語義稍微不夠清晰, 不只包括cpu的load, 還包括D狀態的任務, 這個本身不是大問題, 更多可以認為是feature。
Linux增加了Pressure Stall Information (PSI), PSI從任務的角度分別統計了10/60/300s內因為cpu/io/memory等資源不足而不能運行的時長, 并按照影響范圍分成2類：
- some - 因為缺少資源導致部分任務不能執行。
- full - 因為缺少資源導致所有任務不能執行, cpu不存在這種情況。
我們在一臺96c的arm機器上掃描所有cgroup的cpu.pressure：
這里會引出幾個問題, 篇幅原因這里不再展開。
- 父cgroup的avg為什么比子cgroup還小? 是實現問題還是有額外的配置參數?
- avg10等于33, 也就是1/3的時間有task因為沒有cpu而得不到執行, 考慮到系統cpu利用率在40%左右并不算高,。 我們怎么合理看待和使用這個值：
top - 09:55:41 up 127 days, 1:44, 1 user, load average: 111.70, 87.08, 79.41
Tasks: 3685 total, 21 running, 2977 sleeping, 1 stopped, 8 zombie
%Cpu(s): 27.3 us, 8.9 sy, 0.0 ni, 59.8 id, 0.1 wa, 0.0 hi, 4.0 si, 0.0 st
6.RTFSC
有的時候RTFM已經不夠了, 手冊包括工具本身的更新沒對上內核的節奏, 我們回到上面頁面回收的例子, 估計有的同學之前就有疑問, 沒有scan哪里來的steal。
#sar -B 1
11:00:16 AM pgscank/s pgscand/s pgsteal/s %vmeff
11:00:17 AM 0.00 0.00 3591.00 0.00
11:00:18 AM 0.00 0.00 10313.00 0.00
11:00:19 AM 0.00 0.00 8452.00 0.00
先看sysstat (sar) 里面的實現, 主要是讀取分析/proc/vmstat：
- pgscand: 對應到pgscan_direct域。
- pgscank: 對應到pgscan_kswapd域。
- pgsteal: 對應到pgsteal_開頭的域。
#gdb --args ./sar -B 1
(gdb) b read_vmstat_paging
(gdb) set follow-fork-mode child
(gdb) r
Breakpoint 1, read_vmstat_paging (st_paging=0x424f40) at rd_stats.c:751
751 if ((fp = fopen(VMSTAT, "r")) == NULL)
(gdb) n
754 st_paging->pgsteal = 0;
(gdb)
757 while (fgets(line, sizeof(line), fp) != NULL) {
(gdb)
759 if (!strncmp(line, "pgpgin ", 7)) {
(gdb)
763 else if (!strncmp(line, "pgpgout ", 8)) {
(gdb)
767 else if (!strncmp(line, "pgfault ", 8)) {
(gdb)
771 else if (!strncmp(line, "pgmajfault ", 11)) {
(gdb)
775 else if (!strncmp(line, "pgfree ", 7)) {
(gdb)
779 else if (!strncmp(line, "pgsteal_", 8)) {
(gdb)
784 else if (!strncmp(line, "pgscan_kswapd", 13)) {
(gdb)
789 else if (!strncmp(line, "pgscan_direct", 13)) {
(gdb)
757 while (fgets(line, sizeof(line), fp) != NULL) {
(gdb)
看下/proc/vmstat都有什么：
#grep pgsteal_ /proc/vmstat
pgsteal_kswapd 168563
pgsteal_direct 0
pgsteal_anon 0
pgsteal_file 978205
#grep pgscan_ /proc/vmstat
pgscan_kswapd 204242
pgscan_direct 0
pgscan_direct_throttle 0
pgscan_anon 0
pgscan_file 50583828
最后看看內核的實現, pgsteal和pgscan的邏輯是一樣, 除了nr_scanned換成了nr_reclaimed：
if (current_is_kswapd()) {
if (!cgroup_reclaim(sc))
__count_vm_events(PGSCAN_KSWAPD, nr_scanned);
count_memcg_events(lruvec_memcg(lruvec), PGSCAN_KSWAPD,
nr_scanned);
} else {
if (!cgroup_reclaim(sc))
__count_vm_events(PGSCAN_DIRECT, nr_scanned);
count_memcg_events(lruvec_memcg(lruvec), PGSCAN_DIRECT,
nr_scanned);
}
__count_vm_events(PGSCAN_ANON + file, nr_scanned);
現在問題很清晰了：
- 這里sar取得是系統的/proc/vmstat, 而cgroup里面pgscan_kswapd和pgscan_direct只會加到cgroup的統計,不會加到系統級的統計。
- cgroup里面pgsteal_kswapd和pgsteal_direct同樣只會加到cgroup自己的統計。
- 但是主要pgscan_anon, pgscan_file和pgsteal_anon, pgsteal_file都只加到系統級的統計。
- sar讀取了pgscan_kswapd, pgscan_direct, 以及pgsteal_*, 這里*還包括了pgsteal_anon和pgsteal_file。
這整個邏輯都亂了, 我們有必要解決這個bug讓sar的輸出變得更加有意義. 那么在cgroup內是不是沒問題?
#df -h .
Filesystem Size Used Avail Use% Mounted on
cgroup 0 0 0 - /sys/fs/cgroup/memory
#grep -c 'pgscan\|pgsteal' memory.stat
0
這些統計信息在cgroup v1上完全沒有輸出, 而只在v2版本有輸出. 在以前內核沒有專門LRU_UNEVICTABLE的時候, 如果有很多比如mlock page的時候, 碰到過不停掃描卻不能回收內存的情況, 這個統計會非常有用, 即使是現在我相信這個統計還是有用的, 只是大部分時候還不用看到這么細。
7.多上手
紙上得來終覺淺, 自己動手去做帶來很多好處：
- 回答預設問題. 調試分析就是不斷提出問題和驗證的過程, 沒有上手的話就會一直停留在第一個問題上. 比如我想了解某平臺上物理內存是怎么編址的, 沒有文檔的話只能自己去實驗。
- 提出新的問題. 調試分析中不怕有問題, 怕的是提不出問題。
- 會有意外收獲. 很多時候并不是有意為之, 比如準備的是分析cpu調頻能否降功耗, 上去卻發現系統一直運行在最低頻率。
- 熟練. 熟練就是效率。
- 改進產品. 可以試想下在整個云環境所有機器上掃描 (類似全面體檢) 會發現多少潛在問題。
參考資料
[1]https://www.cs.rice.edu/~johnmc/comp528/lecture-notes/。
[2]https://brendangregg.com/。
[3]http://dtrace.org/blogs/bmc/。
[4]https://blog.stgolabs.net/。
[5]https://lwn.net/。
[6]https://github.com/namhyung/uftrace。
[7]https://www.brendangregg.com/
[8]The Art of Computer Systems Performance Analysis。
