最近在做有关性能优化方面的东西,其中使用到了Profiler,就目前来看除了glibc中自带的gprof以外,还有一个使用的比较广泛的由google开发的GooglePerformance tools,在这篇博文中,我们就来学学gprof这个性能调试工具吧,在介绍gprof之前,我们有必要来思考下我们优化的性能主要包括哪些部分,这部分内容可以参考这篇博文http://coolshell.cn/articles/7490.html,简要地说性能主要包括了:1)吞吐量,2)时延;一般来说,一个系统的性能受到这两个条件的约束,缺一不可。比如,我的系统可以顶得住一百万的并发,但是系统的延迟是2分钟以上,那么,这个一百万的负载毫无意义。系统延迟很短,但是吞吐量很低,同样没有意义。所以,一个好的系统的性能测试必然受到这两个条件的同时作用。 有经验的朋友一定知道,这两个东西的一些关系:Throughput越大,Latency会越差。因为请求量过大,系统太繁忙,所以响应速度自然会低。Latency越好,能支持的Throughput就会越高。因为Latency短说明处理速度快,于是就可以处理更多的请求。这部分内容是完全参考了cool shell的博文,好了,介绍到此,接下来,我们就来看看gprof这个工具吧,测试代码如下:
#include <stdio.h> #include <stdlib.h> int worker1() { int i=0,j=0; while(i++ < 4000000) j+=i; } int worker2() { int i=0,j=0; while(i++ < 400000) j+=i; } int main(int argc,char** argv) { int num = 0; if(argc <2) { printf("usage %s num\n",argv[0]); exit(-1); } num = atoi(argv[1]); while(num--) { worker1(); worker2(); } }
以上是测试代码,首先通过g++ -o Test Test.cpp -pg -lc,来编译,编译完成时会生成gmon.out文件,有了这个文件,我们就可以通过gprof Test gmon.out +编译选项来查看程序的性能情况
1)选项 -p
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 90.65 98.64 98.64 10000 9.86 9.86 worker1() 9.35 108.81 10.17 10000 1.02 1.02 worker2()
从上述代码中,可以看出woker1的操作耗时基本上是worker2的10倍,并且最主要的耗时是在叠加计算上,
2)选项 -q
Call graph (explanation follows) granularity: each sample hit covers 4 byte(s) for 0.01% of 108.81 seconds index % time self children called name <spontaneous> [1] 100.0 0.00 108.81 main [1] 98.64 0.00 10000/10000 worker1() [2] 10.17 0.00 10000/10000 worker2() [3] ----------------------------------------------- 98.64 0.00 10000/10000 main [1] [2] 90.7 98.64 0.00 10000 worker1() [2] ----------------------------------------------- 10.17 0.00 10000/10000 main [1] [3] 9.3 10.17 0.00 10000 worker2() [3] -----------------------------------------------
这个选项相比于-p,其更加详细,从上面可以看出main函数基本上的耗时都在函数调用上,而worker1的耗时是worker2的10倍,
从上述代码测试中,有一个局限性:只能测试用户自行写的程序,而对于通过共享库而使用的一个函数是否也可以检查出来呢,目前在希望从共享库(包括 C 库 libc.a)中获得剖析信息,就需要使用-pg
来编译这些库。幸运的是,很多发行版都提供了已经启用代码剖析支持而编译的 C 库版本(libc_p.a)。下面我们就来看看如何通过共享库来获取程序的各个部分的性能情况,代码如下:
#include <stdio.h> int a(void) { sleep(1); return 0; } int b(void) { sleep(4); return 0; } int main(int argc, char** argv) { int iterations; if(argc != 2) { printf("Usage %s <No of Iterations>\n", argv[0]); exit(-1); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } }
测试结果(g++ -o Test Test.cpp -pg -lc_p;./Test 30)
Flat profile: Each sample counts as 0.01 seconds. no time accumulated % cumulative self self total time seconds seconds calls Ts/call Ts/call name 0.00 0.00 0.00 120 0.00 0.00 sigprocmask 0.00 0.00 0.00 61 0.00 0.00 __libc_sigaction 0.00 0.00 0.00 61 0.00 0.00 sigaction 0.00 0.00 0.00 60 0.00 0.00 nanosleep 0.00 0.00 0.00 60 0.00 0.00 sleep 0.00 0.00 0.00 30 0.00 0.00 a 0.00 0.00 0.00 30 0.00 0.00 b 0.00 0.00 0.00 21 0.00 0.00 _IO_file_overflow 0.00 0.00 0.00 3 0.00 0.00 _IO_new_file_xsputn 0.00 0.00 0.00 2 0.00 0.00 _IO_new_do_write 0.00 0.00 0.00 2 0.00 0.00 __find_specmb 0.00 0.00 0.00 2 0.00 0.00 __guard_setup 0.00 0.00 0.00 1 0.00 0.00 _IO_default_xsputn 0.00 0.00 0.00 1 0.00 0.00 _IO_doallocbuf 0.00 0.00 0.00 1 0.00 0.00 _IO_file_doallocate 0.00 0.00 0.00 1 0.00 0.00 _IO_file_stat 0.00 0.00 0.00 1 0.00 0.00 _IO_file_write 0.00 0.00 0.00 1 0.00 0.00 _IO_setb 0.00 0.00 0.00 1 0.00 0.00 ____strtol_l_internal 0.00 0.00 0.00 1 0.00 0.00 ___fxstat64 0.00 0.00 0.00 1 0.00 0.00 __cxa_atexit 0.00 0.00 0.00 1 0.00 0.00 __errno_location 0.00 0.00 0.00 1 0.00 0.00 __new_exitfn 0.00 0.00 0.00 1 0.00 0.00 __strtol_internal 0.00 0.00 0.00 1 0.00 0.00 _itoa_word 0.00 0.00 0.00 1 0.00 0.00 _mcleanup 0.00 0.00 0.00 1 0.00 0.00 atexit 0.00 0.00 0.00 1 0.00 0.00 atoi 0.00 0.00 0.00 1 0.00 0.00 exit 0.00 0.00 0.00 1 0.00 0.00 flockfile 0.00 0.00 0.00 1 0.00 0.00 funlockfile 0.00 0.00 0.00 1 0.00 0.00 main 0.00 0.00 0.00 1 0.00 0.00 mmap 0.00 0.00 0.00 1 0.00 0.00 moncontrol 0.00 0.00 0.00 1 0.00 0.00 new_do_write 0.00 0.00 0.00 1 0.00 0.00 printf 0.00 0.00 0.00 1 0.00 0.00 setitimer 0.00 0.00 0.00 1 0.00 0.00 vfprintf 0.00 0.00 0.00 1 0.00 0.00 write
尽管 profiler 已经记录了每个函数被调用的确切次数,但是为这些函数记录的时间(实际上是所有函数)都是 0.00。这是因为 sleep
函数实际上是执行了一次对内核空间的调用,从而将应用程序的执行挂起了,然后有效地暂停执行,并等待内核再次将其唤醒。由于花在用户空间执行的时间与花在内核中睡眠的时间相比非常小,因此就被取整成零了。其原因是 gprof 仅仅是通过以固定的周期对程序运行时间 进行采样测量来工作的。因此,当程序不运行时,就不会对程序进行采样测量。
总结
尽管 gprof 存在上面的限制,但是它对于优化代码来说依然是个非常有用的工具,如果您的代码大部分是用户空间 CPU 密集型的,它的用处就更加明显。首先使用time
来运行程序从而判断 gprof 是否能产生有用信息是个好主意。好了,本篇博文到此结束,下篇我们会通过几个实例来进一步学习使用gprof工具进行性能调优。
如果需要,请注明转载,多谢