1. perf
先让 perf 来打头阵。perf top 一下,看看系统内实时的 CPU 消耗(原图丢了,拿个凑数):
再选择 Annotate,找出热点(可以精确到 CPU 指令):
对应着源码
如果你关注的程序有调试符号并且能根据调试符号找到源码,那么 perf 会在相关的指令旁边显示源码。
此时能看出大部分的 CPU 都消耗在链表遍历上了。
追链表是个非常缓存不友好的行为,另外还能看到有个字符串的解引用也会占用大量的 CPU,这里只可能是 cache-miss 了。
perf stat -e cache-references,cache-misses -p <TID> 一下那个线程,发现绝大部分都是 cache-miss。(没法上图,忘记保存了)。
关于 CPU cache,有一个非常有意思的页面,可以感性地认识一下内存相对于缓存有多慢。
通过 perf list 可以看到 perf 具体能统计哪些指标
# 硬件(CPU 中的 Performance Monitor Unit)指标
branch-instructions # 执行的跳转指令数
branch-misses # 分支预测失败数
bus-cycles # 不知道……(以下用 - 代替)
cache-misses # 缓存未命中
cache-references # 缓存访问数
cpu-cycles or cycles # CPU 时钟周期数
instructions # 执行的指令数
ref-cycles # - (跟 bus-cycles 有些乱糟的关系)
stalled-cycles-frontend # CPU 前端等待(前端是指取指/译码、分支预测、访存等等东西,后端是指执行指令的过程)
# 软件指针
alignment-faults # 对齐错误,x86/x64 会自动处理访存不对齐,所以不用关注
bpf-output # 跟 eBPF 有关,不知道是干啥的
context-switches or cs # 上下文切换数(程序被调度走了)
cpu-clock # CPU 时钟(这里是软件统计的,不如上面的准)
cpu-migrations # CPU 迁移(程序从 CPU1 执行,但是被调度到 CPU2 上去了)
dummy # -
emulation-faults # -
major-faults # 主要缺页错误(需要的页不在内存中,要去磁盘上取出再填进去)
minor-faults # 次要缺页错误(需要的页在内存中,只是缺页表项,填上页表项就好了)
page-faults OR faults # == major-faults + minor-faults
task-clock # -
# 硬件指针(Hardware cache event)
L1-dcache-load-misses # L1 资料缓存未命中
L1-dcache-loads # L1 资料缓存访问数
L1-dcache-prefetch-misses # L1 资料缓存预取未命中
L1-dcache-store-misses # L1 资料缓存RFO未命中(RFO: read-for-ownership,读取并且失效这个缓存)
L1-dcache-stores # L1 数据缓存RFO
L1-icache-load-misses # L1 指令缓存未命中
LLC-load-misses # LLC: Last Level Cache,即 L2/L3 缓存。
LLC-loads # 这些根据上面的说明看名子应该能知道是什么
LLC-prefetch-misses # 就不再一个个解释了
LLC-prefetches #
LLC-store-misses #
LLC-stores #
branch-load-misses # BPU 缓存未命中(BPU:Branch Processing Unit)
branch-loads # 与分支预测有关的缓存
dTLB-load-misses # 资料 TLB 缓存未命中(TLB: Translation Lookaside Buffer)
dTLB-loads # TLB 是页表的缓存,用来加速虚拟地址->物理地址(VA->PA)转换的
dTLB-store-misses # 同不一个个解释了……
dTLB-stores #
iTLB-load-misses # 指令 TLB 缓存未命中
iTLB-loads #
node-load-misses # 本地访存未命中,需要跨 NUMA node(其实就是 CPU)访存
node-loads # 访存数(这里访存数跟 LLC miss 对不上号,因为 LLC miss 后可能会跨 core 取到缓存)
node-prefetch-misses #
node-prefetches #
node-store-misses #
node-stores #
找到了热点,下一步就是给 MongoDB 打上补丁,目的主要是优化缓存
http://link.zhihu.com/?target=...
2. SystemTap
想知道每次 __evict_clear_all_walks (__evict_server 调用了这个函数)具体耗费了多上时间?貌似 perf 不太擅长做这个
那么这时候就可以用 SystemTap 了:
global times
probe process("/usr/bin/mongod").function("__evict_clear_all_walks").return {
times <<< gettimeofday_us() - @entry(gettimeofday_us())
}
probe timer.s(1) {
print(@hist_linear(times, 16000, 36000, 500))
}
直方图左边的数字是函数执行的时间,单位是 us,右边是落在这个区间内的次数。
【打补丁前】
value |-------------------------------------------------- count
16400 |@ 4
16600 |@@@@ 14
16800 |@@@@ 13
17000 | 1
17200 |@ 5
17400 |@@@ 10
17600 |@ 3
17800 |@@@@@@@@ 24
18000 |@@@@@@@@@@@@@@@@@@@@@ 63
18200 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 92
18400 |@@@@@@@@@@@@@@@@@ 53
18600 |@@@@@@@@@@@@@@@@@@@@@@@@@@ 80
18800 |@@@@@@@@ 26
19000 |@@@@@@@@@@@@@ 39
19200 |@@@@@@@@ 24
19400 |@@@@ 12
19600 |@ 3
19800 |@ 5
20000 | 2
20200 |@@ 7
20400 |@@@ 11
20600 |@@@ 9
20800 |@@ 8
21000 |@@@ 11
21200 |@@@@@@@ 21
21400 |@@@@@@@ 22
21600 |@@@@@@@@@@@@@@@@@@@@ 60
21800 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 121
22000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 131
22200 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 95
22400 |@@@@@@@@@@@@@@@@@@@@ 61
22600 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 81
22800 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 87
23000 |@@@@@@@@@@@@@@@@@@@@@@ 67
23200 |@@@@@@@@@@@@@@@@ 50
23400 |@@@@@ 15
23600 |@ 4
23800 |@ 4
24000 | 2
【打补丁后】
4900 | 6
5000 |@@@@@@@ 295
5100 |@@@@@@@@@@@ 430
5200 |@ 55
5300 | 17
5400 | 25
5500 | 30
5600 | 13
5700 | 16
5800 | 19
5900 | 8
6000 | 9
6100 | 16
6200 | 14
6300 |@ 67
6400 |@@@@ 175
6500 |@@@@@@@ 293
6600 |@@ 109
6700 |@@ 78
6800 |@@ 89
6900 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1864
7000 |@@@@ 171
7100 | 29
7200 | 22
7300 | 8
SystemTap 是目前 Linux 最强大的 tracer/profiler,可以跟踪内核以及用户态程序中的任意函数、syscall、语句甚至指令,还可以跟踪 DTrace 的 USDT(写在代码中的预定义的 trace point,比如刚才提到的 MongoDB 补丁代码中的那句 DTRACE_PROBE(proton, dhandle_not_file)。