从2.6.31内核开始,linux内核自带了一个性能分析工具perf,能够进行函数级与指令级的热点查找。通过它,应用程序可以利用 PMU,tracepoint 和内核中的特殊计数器来进行性能统计。它不但可以分析指定应用程序的性能问题 (per thread),也可以用来分析内核的性能问题,当然也可以同时分析应用代码和内核,从而全面理解应用程序中的性能瓶颈。
Perf是内置于Linux内核源码树中的性能剖析(profiling)工具。它基于事件采样原理,以性能事件为基础,支持针对处理器相关性能指标与操作系统相关性能指标的性能剖析,常用于性能瓶颈的查找与热点代码的定位。
安装 perf 非常简单, 只要内核版本高于2.6.31的, perf已经被内核支持. 首先安装内核源码:
apt-get install linux-source
那么在 /usr/src 目录下就已经下载好了内核源码, 我们对源码包进行解压, 然后进入 tools/perf 目录然后敲入下面两个命令即可:
make
make install
可能因为系统原因, 需要提前安装下面的开发包:
apt-get install -y binutils-dev
apt-get install -y libdw-dev
apt-get install -y Python/ target=_blank class=infotextkey>Python-dev
apt-get install -y libnewt-dev
CPU周期(cpu-cycles)是默认的性能事件,所谓的CPU周期是指CPU所能识别的最小时间单元,通常为亿分之几秒,是CPU执行最简单的指令时所需要的时间,例如读取寄存器中的内容,也叫做clock tick。
perf COMMAND [-e event ...] PROGRAM, perf 是采用的这么一个命令格式, COMMAND一般常用的就是 top, stat, record, report等. 然后用 -e 参数来统计需要关注的事件. 多个事件就用多个 -e 连接。
Perf是一个包含22种子工具的工具集,以下是最常用的5种:
perf-list
Perf-list用来查看perf所支持的性能事件,有软件的也有硬件的。
List all symbolic event types。
perf list [hw | sw | cache | tracepoint | event_glob]
perf stat
说明一个工具的最佳途径是列举一个例子。考查下面这个例子程序。其中函数 longa() 是个很长的循环,比较浪费时间。函数 foo1 和 foo2 将分别调用该函数 10 次,以及 100 次。
//t1.c
void longa()
{
int i,j;
for(i = 0; i < 1000000; i++)
j=i; //am I silly or crazy? I feel boring and desperate.
}
void foo2()
{
int i;
for(i=0 ; i < 10; i++)
longa();
}
void foo1()
{
int i;
for(i = 0; i< 100; i++)
longa();
}
int mAIn(void)
{
foo1();
foo2();
}
然后编译它:
gcc -o t1 -g t1.c
下面演示了 perf stat 针对程序 t1 的输出:
root@ubuntu-test:~# perf stat ./t1
Performance counter stats for './t1':
218.584169 task-clock # 0.997 CPUs utilized
18 context-switches # 0.000 M/sec
0 CPU-migrations # 0.000 M/sec
82 page-faults # 0.000 M/sec
771,180,100 cycles # 3.528 GHz
<not counted> stalled-cycles-frontend
<not counted> stalled-cycles-backend
550,703,114 instructions # 0.71 insns per cycle
110,117,522 branches # 503.776 M/sec
5,009 branch-misses # 0.00% of all branches
0.219155248 seconds time elapsed
程序 t1 是一个 CPU bound 型,因为 task-clock-msecs 接近 1
对 t1 进行调优应该要找到热点 ( 即最耗时的代码片段 ),再看看是否能够提高热点代码的效率。缺省情况下,除了 task-clock-msecs 之外,perf stat 还给出了其他几个最常用的统计信息:
通过指定 -e 选项,您可以改变 perf stat 的缺省事件 ( 关于事件,在上一小节已经说明,可以通过 perf list 来查看 )。假如您已经有很多的调优经验,可能会使用 -e 选项来查看您所感兴趣的特殊的事件。
有些程序慢是因为计算量太大,其多数时间都应该在使用 CPU 进行计算,这叫做 CPU bound 型;有些程序慢是因为过多的 IO,这种时候其 CPU 利用率应该不高,这叫做 IO bound 型;对于 CPU bound 程序的调优和 IO bound 的调优是不同的。
perf top
使用 perf stat 的时候,往往您已经有一个调优的目标。比如我刚才写的那个无聊程序 t1。
也有些时候,您只是发现系统性能无端下降,并不清楚究竟哪个进程成为了贪吃的 hog。
此时需要一个类似 top 的命令,列出所有值得怀疑的进程,从中找到需要进一步审查的家伙。
Perf top 用于实时显示当前系统的性能统计信息。该命令主要用来观察整个系统当前的状态,比如可以通过查看该命令的输出来查看当前系统最耗时的内核函数或某个用户进程。
让我们再设计一个例子来演示吧,我很快就想到了如代码清单 2 所示的一个程序:
//t2.c
main(){
int i;
while(1) i++;
}
然后编译这个程序:
gcc -o t2 -g t2.c
运行这个程序后, 我们另起一个窗口,运行perf top来看看:
Events: 8K cycles
98.67% t2 [.] main
1.10% [kernel] [k] __do_softirq
0.07% [kernel] [k] _raw_spin_unlock_irqrestore
0.05% perf [.] kallsyms__parse
0.05% libc-2.15.so [.] 0x807c7
0.05% [kernel] [k] kallsyms_expand_symbol
0.02% perf [.] map__process_kallsym_symbol
很容易便发现 t2 是需要关注的可疑程序。不过其作案手法太简单:肆无忌惮地浪费着 CPU。所以我们不用再做什么其他的事情便可以找到问题所在。但现实生活中,影响性能的程序一般都不会如此愚蠢,所以我们往往还需要使用其他的 perf 工具进一步分析。
使用 perf record, 解读 report
使用 top 和 stat 之后,您可能已经大致有数了。要进一步分析,便需要一些粒度更细的信息。比如说您已经断定目标程序计算量较大,也许是因为有些代码写的不够精简。那么面对长长的代码文件,究竟哪几行代码需要进一步修改呢?这便需要使用 perf record 记录单个函数级别的统计信息,并使用 perf report 来显示统计结果。
您的调优应该将注意力集中到百分比高的热点代码片段上,假如一段代码只占用整个程序运行时间的 0.1%,即使您将其优化到仅剩一条机器指令,恐怕也只能将整体的程序性能提高 0.1%。俗话说,好钢用在刀刃上,不必我多说了。
perf record -e cpu-clock ./t1
perf report
perf report 输出结果:
Events: 229 cpu-clock
100.00% t1 t1 [.] longa
不出所料,hot spot 是 longa( ) 函数。但,代码是非常复杂难说的,t1 程序中的 foo1() 也是一个潜在的调优对象,为什么要调用 100 次那个无聊的 longa() 函数呢?但我们在上图中无法发现 foo1 和 foo2,更无法了解他们的区别了。
我曾发现自己写的一个程序居然有近一半的时间花费在 string 类的几个方法上,string 是 C++ 标准,我绝不可能写出比 STL 更好的代码了。因此我只有找到自己程序中过多使用 string 的地方。因此我很需要按照调用关系进行显示的统计信息。
使用 perf 的 -g 选项便可以得到需要的信息:
perf record -e cpu-clock -g ./t1
perf report
输出结果:
Events: 270 cpu-clock
- 100.00% t1 t1 [.] longa
- longa
+ 91.85% foo1
+ 8.15% foo2
通过对 calling graph 的分析,能很方便地看到 91.85% 的时间都花费在 foo1() 函数中,因为它调用了 100 次 longa() 函数,因此假如 longa() 是个无法优化的函数,那么程序员就应该考虑优化 foo1,减少对 longa() 的调用次数。
使用 tracepoint
当 perf 根据 tick 时间点进行采样后,人们便能够得到内核代码中的 hot spot。那什么时候需要使用 tracepoint 来采样呢?
我想人们使用 tracepoint 的基本需求是对内核的运行时行为的关心,如前所述,有些内核开发人员需要专注于特定的子系统,比如内存管理模块。这便需要统计相关内核函数的运行情况。另外,内核行为对应用程序性能的影响也是不容忽视的:
以之前的遗憾为例,假如时光倒流,我想我要做的是统计该应用程序运行期间究竟发生了多少次系统调用。在哪里发生的?
下面我用 ls 命令来演示 sys_enter 这个 tracepoint 的使用:
root@ubuntu-test:~# perf stat -e raw_syscalls:sys_enter ls
bin libexec off perf.data.old t1 t3 tutong.iso
bwtest minicom.log perf.data pktgen t1.c t3.c
Performance counter stats for 'ls':
111 raw_syscalls:sys_enter
0.001557549 seconds time elapsed
个报告详细说明了在 ls 运行期间发生了多少次系统调用 ( 上例中有 111 次 )。
性能测试大致分以下几个步骤:
需求描述:有一个服务,启动时会加载一个1G的词表文件到内存,请求来了之后,会把请求词去词表里做模糊匹配,如果匹配到了就向一个后端服务发送一条http请求,拿回数据之后,返回给客户端的同时,向MySQL记录请求的唯一标识和一个请求次数的标记;
其中有几个关键函数
模糊匹配(fuzzyMatching)
后端请求函数(sendingRequest)
拼装请求函数(buildResponse)
记录mysql请求次数标记(signNum)
问题及分析:
第一组:完全随机请求词,qps达到1k时,服务器未见异常,cpu、内存、带宽均未满,qps无法继续提升;
第二组:解决后端服务的问题后,第二组使用平均30个字的请求词,来打压,qps到400时,cpu load已满;
第三组:解决了上述两个问题之后,使用完全随机请求词,qps到达3k后降低至1k,然后再次提升到3k,如此反复;
第四组:将后端换做真实的服务来做整体压测,发现qps最高只能到300,此时检查各项指标,发现入口带宽占满了;
这里简单说一下如何使用perf+火焰图来直观的定位性能问题:
perf
Perf 拥有了众多的性能分析能力,举例来说,使用 Perf 可以计算每个时钟周期内的指令数,称为 IPC,IPC 偏低表明代码没有很好地利用 CPU。Perf 还可以对程序进行函数级别的采样,从而了解程序的性能瓶颈究竟在哪里等等。Perf 还可以替代 strace,可以添加动态内核 probe 点,还可以做 benchmark 衡量调度器的好坏。
生成火焰图
1、第一步:使用压力测试工具对程序进行打压,压到程序拐点;
$sudo perf record -e cpu-clock -g -p 11110
Ctrl+c结束执行后,在当前目录下会生成采样数据perf.data.
2、第二步:用perf 工具对perf.data进行解析
perf -i perf.data &> perf.unfold
3、第三步:将perf.unfold中的符号进行折叠:
./stackcollapse-perf.pl perf.unfold &> perf.folded
4、最后生成svg图:
./flamegraph.pl perf.folded > perf.svg
到这儿可以生成函数调用火焰图,如下图:
原生的perf可以直接定位C/C++的程序,通常编译debug版本的程序能看到更多的信息,JAVA、go等语言可以通过各自定制的工具来生成,原理类似;通过火焰图可以轻松定位到哪个函数的处理时间最长,从而找到问题所在。