CPU Profiling: What, How, and When
2025年3月10日 · 2862 字 · 6 分钟 · Performance Analysis
What: 什么是CPU Profiling
一种程序CPU性能分析的技术。通过收集程序执行时的详细数据(例如函数调用频率、耗时、调用栈等),帮助开发者识别性能瓶颈,优化代码效率。一般用于性能分析,根因诊断的场景。
How: Profiling 数据是怎么获取的
常见的工具比如perf
,用于采集进程堆栈信息。这里工具通过抽样统计的方式,获取在CPU上执行的堆栈样本然后进行性能分析。
graph TD
A[采样触发] -->|中断| B[采样]
B -->|perf_event/ebpf| C[进程堆栈地址]
C -->|地址翻译| D[ELF, OFFSET]
D -->|符号翻译| E[调用栈]
E -->|格式化| F[pprof/perf script]
F --> |绘图| G[火焰图/调用图]
触发机制
一般使用定时中断或者基于事件计数的策略。
定时中断: 默认使用固定频率(如 99Hz
)的时钟中断(SIGPROF
),中断间隔越短,精度越高,但开销越大。如 Linux perf
默认使用 99Hz
频率。定时器每隔 1/99 ≈ 10.1ms
发送一个中断信号(如 SIGPROF
)。
事件计数器采样: 基于硬件性能计数器(如 PERF_COUNT_HW_CPU_CYCLES
, PERF_COUNT_HW_INSTRUCTIONS
),在达到阈值时触发采样。比如Cache_Miss频繁的时候进行采样,这类策略可以基于硬件的负载情况进行采样的调度。
采样方法
一般会使用 OS 内核提供的epbf 或者 perf event 接口进行堆栈采样。
前者可以通过 eBPF 程序(如 bpf_get_stackid
)直接捕获完整用户态和内核态调用栈,无需额外堆栈回溯,获取到完整的堆栈IP 信息。
使用 perf_event_open
接口获取指令指针(RIP),比如perf record命令,此时无法获取完整的调用栈,只获取了当前执行的函数地址,所以也只能根据地址找到触发采样的函数名称
node 3236535 34397396.208842: 250000 cpu-clock:pppH: 110c800 v8::internal::Heap_CombinedGenerationalAndSharedBarrierSlow+0x0 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
node 3236535 34397396.354632: 250000 cpu-clock:pppH: 7f7d63e87ef4 Builtins_LoadIC+0x574 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
node 3236535 34397396.451226: 250000 cpu-clock:pppH: ffffffff889bbb0e syscall_enter_from_user_mode+0xe ([kernel.kallsyms])
node 3236535 34397397.580029: 250000 cpu-clock:pppH: 18c73f1 uv__metrics_update_idle_time+0x11 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
node 3236535 34397397.649952: 250000 cpu-clock:pppH: 7f7d63e87f0f Builtins_LoadIC+0x58f (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
node 3236535 34397399.340595: 250000 cpu-clock:pppH: 7f7d63e8b353 Builtins_LoadICTrampoline+0x13 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
node 3236535 34397399.340842: 250000 cpu-clock:pppH: 7f7d6ba9022c malloc+0x18c (/usr/lib/x86_64-linux-gnu/libc.so.6)
node 3236535 34397399.341095: 250000 cpu-clock:pppH: 19d3913 Builtins_FulfillPromise+0x193 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
通过Stack Unwind(比如libunwind
)进行堆栈回溯以此来获取完整的堆栈信息,perf record -g
。
stack unwind 参考: https://zhuanlan.zhihu.com/p/460686470
node 3236535 34397238.259753: 250000 cpu-clock:pppH:
7f7d44339100 [unknown] (/tmp/perf-3236535.map)
18ea0dc Builtins_JSEntryTrampoline+0x5c (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
18e9e03 Builtins_JSEntry+0x83 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
106692b v8::internal::(anonymous namespace)::Invoke+0x12b (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
10679c4 v8::internal::Execution::Call+0x64 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
f2a09d v8::Function::Call+0x14d (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
c1c738 node::Environment::RunTimers+0x208 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
18c46f2 uv__run_timers+0x22 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
18c8524 uv_run+0x2f4 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
bd3be6 node::SpinEventLoopInternal+0x156 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
d18564 node::NodeMainInstance::Run+0x94 (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
d18ffd node::NodeMainInstance::Run+0xcd (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
c7d43f node::Start+0x58f (/root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node)
7f7d6ba14d90 __libc_start_call_main+0x80 (/usr/lib/x86_64-linux-gnu/libc.so.6)
地址翻译
采样后得到的地址信息是进程的虚拟地址信息,即:
7f7d44339100
18ea0dc
18e9e03
106692b
10679c4
f2a09d
c1c738
18c46f2
18c8524
bd3be6
d18564
d18ffd
c7d43f
7f7d6ba14d90
我们还需要将虚拟地址翻译成 ELF + OFFSET ,以便下一步进行函数符号的翻译。
利用/proc/pid/maps
里记录的信息就可以实现V_ADDR --> (ELF, OFFSET)
的翻译。maps里记录的信息的关键信息有:<地址范围> <权限> <文件偏移> <inode> <文件路径>
procfs maps 参考: https://man7.org/linux/man-pages/man5/proc_pid_maps.5.html
00400000-00b81000 r--p 00000000 fc:03 550055 /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node
00b81000-00b83000 r-xp 00781000 fc:03 550055 /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node
......
7f7d6bf3c000-7f7d6bf3d000 ---p 0021a000 fc:03 67 /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.30
7f7d6bf3d000-7f7d6bf48000 r--p 0021a000 fc:03 67 /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.30
7f7d6bf48000-7f7d6bf4b000 rw-p 00225000 fc:03 67 /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.30
......
7f7d6bf52000-7f7d6bf53000 rw-p 00003000 fc:03 3952 /usr/lib/x86_64-linux-gnu/libdl.so.2
......
7f7d6bf56000-7f7d6bf57000 ---p 00000000 00:00 0
7f7d6bf57000-7f7d6bf61000 rw-p 00000000 00:00 0
7f7d6bf61000-7f7d6bf63000 r--p 00000000 fc:03 2928 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f7d6bf63000-7f7d6bf8d000 r-xp 00002000 fc:03 2928 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f7d6bf8d000-7f7d6bf98000 r--p 0002c000 fc:03 2928 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f7d6bf99000-7f7d6bf9b000 r--p 00037000 fc:03 2928 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f7d6bf9b000-7f7d6bf9d000 rw-p 00039000 fc:03 2928 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
maps里记录了不同ELF段在虚拟内存的映射,以及对应ELF文件基地址。我们使用函数把虚拟地址匹配到ELF段,之后再基于地址偏移我们就可以找到相对ELF文件偏移地址,即offset = 虚拟地址 - 内存段起始地址 + 文件偏移
符号翻译
通过地址翻译,我们现在找到了虚拟地址对应的[ELF, offset]
。基于这个信息,我们可以结合符号表以及调试信息翻译出堆栈符号。
使用 ELF 文件中的符号表,或者使用 dwarf debuginfo
的信息,我们可以将地址翻译成函数符号。
比如读取动态库的dynsym
部分记录的函数符号信息,再根据offset查找。
# nm -D /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node | grep malloc
# <地址> <类型> <符号名>
00000000055f9d18 D ares_malloc
0000000001f1a2a0 T ares_malloc_data
0000000001f1b6e0 T ares_malloc_zero
0000000001bf5680 T CRYPTO_malloc
0000000001bf67d0 T CRYPTO_secure_malloc
0000000001bf66f0 T CRYPTO_secure_malloc_done
0000000001bf62d0 T CRYPTO_secure_malloc_init
0000000001bf67c0 T CRYPTO_secure_malloc_initialized
U malloc@GLIBC_2.2.5
U malloc_usable_size@GLIBC_2.2.5
0000000001f5cce0 T nghttp2_mem_malloc
0000000001fdaaa0 T ngtcp2_mem_malloc
00000000020853f0 T uprv_malloc_75
又或者读取ELF的dwarf信息,不仅能找到符号表,还能获取函数在源码中的位置。
# readelf --debug-dump=info /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node | less
<1><1980>: Abbrev Number: 41 (DW_TAG_subprogram)
<1981> DW_AT_external : 1
<1981> DW_AT_name : (indirect string, offset: 0x734): uv__make_close_pending # function name
<1985> DW_AT_decl_file : 19
<1986> DW_AT_decl_line : 247
<1987> DW_AT_decl_column : 6
<1988> DW_AT_prototyped : 1
<1988> DW_AT_declaration : 1
<1988> DW_AT_sibling : <0x1992>
<2><198c>: Abbrev Number: 21 (DW_TAG_formal_parameter)
<198d> DW_AT_type : <0x12a8>
<2><1991>: Abbrev Number: 0
<1><1992>: Abbrev Number: 42 (DW_TAG_subprogram)
<1993> DW_AT_external : 1
<1993> DW_AT_name : (indirect string, offset: 0x1022): __assert_fail
<1997> DW_AT_decl_file : 18
<1998> DW_AT_decl_line : 67
<1999> DW_AT_decl_column : 13
<199a> DW_AT_prototyped : 1
<199a> DW_AT_noreturn : 1
<199a> DW_AT_declaration : 1
<199a> DW_AT_sibling : <0x19b3>
得到了符号后,部分符号需要做demangle处理,以提升可读性,比如使用c++filt工具:
将C++源程序标识符(original C++ source identifier)转换成C++ ABI标识符(C++ ABI identifier)的过程称为mangle;相反的过程称为demangle。
# nm -D /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node | grep T | tail
0000000005611b78 u _ZZN5cppgc8internal14StatsCollector13InternalScopeILNS1_13TraceCategoryE0ELNS1_12ScopeContextE1EE14StartTraceImplEvE28trace_event_unique_atomic448
000000000562bb60 u _ZZNK2v88internal8compiler26SimplifiedLoweringVerifier15InputTruncationEPNS1_4NodeEiE14any_truncation
0000000002875e70 u _ZZNK4node7TCPWrap14MemoryInfoNameEvE20error_and_abort_args
0000000003480720 u _ZZNSt8__detail13__to_chars_16IjEENSt9enable_ifIXsrSt5__or_IJS2_IJSt7is_sameINSt9remove_cvIT_E4typeEaES3_IS7_sES3_IS7_iES3_IS7_lES3_IS7_xES3_IS7_nEEES2_IJS3_IS7_hES3_IS7_tES3_IS7_jES3_IS7_mES3_IS7_yES3_IS7_oEEES3_IcS7_EEE5valueESt15to_chars_resultE4typeEPcSR_S5_E8__digits
000000000281a780 u _ZZNSt8__detail18__to_chars_10_implIjEEvPcjT_E8__digits
000000000281a6a0 u _ZZNSt8__detail18__to_chars_10_implImEEvPcjT_E8__digits
0000000002122cc0 W _ZZSt9call_onceIRFvvEJEEvRSt9once_flagOT_DpOT0_ENUlvE0_4_FUNEv
0000000005600930 u _ZZZN4node14ThreadPoolWork12ScheduleWorkEvENKUlP9uv_work_sE_clES2_E27trace_event_unique_atomic42
0000000005600928 u _ZZZN4node14ThreadPoolWork12ScheduleWorkEvENKUlP9uv_work_sE_clES2_E27trace_event_unique_atomic45
0000000005600920 u _ZZZN4node14ThreadPoolWork12ScheduleWorkEvENKUlP9uv_work_siE0_clES2_iE27trace_event_unique_atomic51
# demangle 处理后
# nm -D /root/.vscode-server/cli/servers/Stable-e54c774e0add60467559eb0d1e229c6452cf8447/server/node | grep T | tail | c++filt
0000000005611b78 u cppgc::internal::StatsCollector::InternalScope<(cppgc::internal::StatsCollector::TraceCategory)0, (cppgc::internal::StatsCollector::ScopeContext)1>::StartTraceImpl()::trace_event_unique_atomic448
000000000562bb60 u v8::internal::compiler::SimplifiedLoweringVerifier::InputTruncation(v8::internal::compiler::Node*, int) const::any_truncation
0000000002875e70 u node::TCPWrap::MemoryInfoName() const::error_and_abort_args
0000000003480720 u std::__detail::__to_chars_16<unsigned int>(char*, char*, unsigned int)::__digits
000000000281a780 u std::__detail::__to_chars_10_impl<unsigned int>(char*, unsigned int, unsigned int)::__digits
000000000281a6a0 u std::__detail::__to_chars_10_impl<unsigned long>(char*, unsigned int, unsigned long)::__digits
0000000002122cc0 W std::call_once<void (&)()>(std::once_flag&, void (&)())::{lambda()#2}::_FUN()
0000000005600930 u node::ThreadPoolWork::ScheduleWork()::{lambda(uv_work_s*)#1}::operator()(uv_work_s*) const::trace_event_unique_atomic42
0000000005600928 u node::ThreadPoolWork::ScheduleWork()::{lambda(uv_work_s*)#1}::operator()(uv_work_s*) const::trace_event_unique_atomic45
0000000005600920 u node::ThreadPoolWork::ScheduleWork()::{lambda(uv_work_s*, int)#2}::operator()(uv_work_s*, int) const::trace_event_unique_atomic51
堆栈输出
按照指定格式组织堆栈信息,比如pprof / perf script
的格式,有时候可以附带上一些辅助集合的元信息(比如容器ID, 业务类型)以便更好的聚合,处理,使用数据
数据展示
上述的堆栈格式通过工具最终都能转换为火焰图和调用图。
When: 什么时候该使用CPU Profiling工具
在相同一段时间内,监控描述了程序运行状态,堆栈代表了程序的具体行为,大部分场景两者可以互相佐证。
graph TD
A[业务异常现象:不可用/性能抖动] --> N[确定需要排查的主体以及异常时间段]
N --> B[观察核心指标: cpu,mem,disk,iops,qps/tps等]
B --> C[排查结论]
B -->|需要进一步分析| D[查看异常时间段堆栈]
D --> C
一般在与CPU有关的根因分析,性能分析这类场景会使用,比如以下场景:
场景分类 | 典型表现 | 工具选择 | 数据采集策略 |
---|---|---|---|
突发性CPU毛刺 | 监控图表出现锯齿状CPU峰值 | - 持续Profiling系统 | 峰值前后5分钟上下文捕获 / 常规采样 |
版本性能回归 | 新版本发布后QPS/TPS下降 | - Differential FlameGraph | A/B版本对比采样 |
CpuSys高 | OS内核态Cpu较高占用,导致主机性能抖动 | - FlameGraph or Call-Chain Graph | 常规采样,分析内核堆栈 |
显然,当程序没有在CPU上稳定运行,Profiling得到的数据价值就会大大降低,比如IO Bound,频繁上下文切换,瞬时进程。此时可能需要更换分析工具。
graph TD
A[CPU Profiling 不适用场景] --> B[内存瓶颈]
A --> C[I/O 密集型]
A --> D[锁竞争]
A --> E[短生命周期进程]
B -->|特征| B2("高 Page Fault/Swap、GC 停顿明显")
B -->|工具| B3{{"Heap Profiler、vmstat"}}
C -->|特征| C2("低 CPU 利用率 iowait > 30%")
C -->|工具| C3{{"iostat、blktrace"}}
D -->|特征| D2("sys% 高上下文切换频繁")
D -->|工具| D3{{"perf lock、lockstat"}}
E -->|特征| E2("进程存活时间 < 采样间隔")
E -->|工具| E3{{"execsnoop、动态插桩"}}
Ref
-
stack unwind: https://zhuanlan.zhihu.com/p/460686470
-
proc_pid_maps: https://man7.org/linux/man-pages/man5/proc_pid_maps.5.html
-
demange & mangle: https://www.cnblogs.com/BloodAndBone/p/7912179.html