文本模式有看起来像这样的输出线:
这将有很多线路,例如,收集的个人资料:
$ CPUPROFILE=a.pprof LD_PRELOAD=./libprofiler.so ./a.out
程序a.out
是相同的如下所示:Kcachegrind/callgrind is inaccurate for dispatcher functions?
然后用pprof分析它top
命令:
$ pprof ./a.out a.pprof
Using local file ./a.out.
Using local file a.pprof.
Welcome to pprof! For help, type 'help'.
(pprof) top
Total: 185 samples
76 41.1% 41.1% 76 41.1% do_4
51 27.6% 68.6% 51 27.6% do_3
37 20.0% 88.6% 37 20.0% do_2
21 11.4% 100.0% 21 11.4% do_1
0 0.0% 100.0% 185 100.0% __libc_start_main
0 0.0% 100.0% 185 100.0% dispatcher
0 0.0% 100.0% 34 18.4% first2
0 0.0% 100.0% 42 22.7% inner2
0 0.0% 100.0% 68 36.8% last2
0 0.0% 100.0% 185 100.0% main
那么,这里是什么:总样本数为185;频率是默认值(每10 ms 1个采样;或每秒100个采样)。那么总运行时间是〜1.85秒。
第一列是a.out在给定函数中工作时采样的数量。如果我们将其除以频率,我们将得到给定函数的总时间估计,例如, do_4
运行为〜0.8秒
第二列是在给定的函数的样本计数由总计数划分,或在总程序运行时间这个函数的百分比。所以do_4
是最慢的功能(总编程时间的41%),而do_1
只是程序运行时间的11%。我想你对这个专栏感兴趣。
第三列是当前和前面行的总和;所以我们可以知道2个最慢的函数,do_4
和do_3
总计占总运行时间的68%(41%+ 27%)
第四和第五列如同第一和第二列;但是这些不仅要考虑给定函数本身的样本,还要考虑直接或间接从给定函数中调用的所有函数的样本。你可以看到,main
和所有从它调用的是100%的总运行时间(因为main
是程序本身;或程序的调用树的根)和last2
与它的孩子是运行时的36.8%(其子程序在我的程序中:半呼叫do_4
和呼叫的一半到do_3
= 41.1 + 27.6/2 = 69.7/2〜= 34%+的功能本身)
PS一段时间:还有一些其他有用pprof命令,如callgrind
或gv
,其显示添加了分析信息的呼叫树的图形表示。