用Gprof优化or测试你的程序
昨天去席老师哪里论文格式审查，回来再次修改论文。这一段时间，忙的简直要抽风了，改论文，看论文，再改论文…总算差不多了。
最近写论文的时候，第五章要写到一个测试，其中包括性能测试。本意是想测出系统中每个模块的性能，也就是每个模块运行次数以及运行时间。经过一番的百度和谷歌，最后决定使用Linux平台的Gprof。Gprof是一个GNU Profiler工具，其中GProf可以打印出每个函数的运行次数以及运行消耗时间，并且可以打印出函数的调用关系，配合KProf还可以显示函数的调用关系树。因此本测试使用Gprof，可以查看进程处理时间耗费情况。
使用Gprof之前，我们有必要了解一下他的工作原理：通过在编译和链接程序的时候（使用-pg编译和链接选项），gcc在应用程序的每个函数中都加入了一个名为mcount (or”_mcount”,or “__mcount”, 依赖于编译器或操作系统)的函数，也就是说你的应用程序里的每一个函数都会调用mcount,而mcount 会在内存中保存一张函数调用图，并通过函数调用堆栈的形式查找子函数和父函数的地址。这张调用图也保存了所有与函数相关的调用时间，调用次数等等的所有信息。
Gprof的用法：gprof [ -b ] [ -e Name ] [ -E Name ] [ -f Name ] [ -F Name ] [ -L PathName ] [ -s ] [ -z] [ a.out [ gmon.out ... ] ]
-b 不再输出统计图表中每个字段的详细描述。
-p 只输出函数的调用图（Call graph的那部分信息）。
-q 只输出函数的时间消耗列表。
-e Name 不再输出函数Name 及其子函数的调用图（除非它们有未被限制的其它父函数）。可以给定多个 -e 标志。一个 -e 标志只能指定一个函数。
-E Name 不再输出函数Name 及其子函数的调用图，此标志类似于 -e 标志，但它在总时间和百分比时间的计算中排除了由函数Name 及其子函数所用的时间。
-f Name 输出函数Name 及其子函数的调用图。可以指定多个 -f 标志。一个 -f 标志只能指定一个函数。
-F Name 输出函数Name 及其子函数的调用图，它类似于 -f 标志，但它在总时间和百分比时间计算中仅使用所打印的例程的时间。可以指定多个 -F 标志。一个 -F 标志只能指定一个函数。-F 标志覆盖 -E 标志。
-z 显示使用次数为零的函数（按照调用计数和累积时间计算）。
使用例子：
假如我写了一个程序count_data.cpp，如果要使用gprof的话，在编译程序的时候需要加上-pg，如下：
g++ -gp -o count_data count_data.cpp
编译没有错误的话，直接运行 count_data程序
./ count_data
运行过程序以后，会在程序当前文件夹下生成一个gmon.out文件，这个文件便是程序运行记录文件。下一步我们就可以使用gprof来读取分析该文件了。
gprof –q test gmon.out
如果你想多次运行程序并且记录函数运行时间，便可以用shell来实现。下面是我写的一个shell脚本。测试本程序运行。本程序被调用四次，每次传入不同参数。
#!/bin/sh
i=1
while [ $i -le 23 ]
do
echo $i
time ./count_data $i > null
cp gmon.out ${i}gmon.out
gprof -b count_data ${i}gmon.out > ${i}.txt
let i+=7
done
通过上面shell的运行，程序会产生一下几个文件：
1.txt 2.txt 3.txt 4.txt
我们可以统计该程序运行函数的时间来分析每个函数的性能。该功能可以对程序运行效率进行优化，也可以在写论文是完成测试。呵呵，下面是我的测试结果以及对测试结果的分析，直接在论文里复制出来了，懒得改了，呵呵
本次测试过程如下，首先将数据库中数据清空，然后程序循环读取七天的离线数据，模拟在线统计一小时数据，进行处理。处理过程中记录下该数据记录条数，以及更新数据条数。对Gprof产生的gmon.out文件进行分析。依次运行和分析第二批数据、第三批和第四批数据。
表1主要函数运行时间
函数名(耗时ms) 第一批 第二批 第三批 第四批 get_userid() 86733 116327 110690 120245 count_net() 54571 77240 70421 72147 update_max_area() 小于10 小于10 小于10 小于10 Insert_hourflow() 小于10 小于10 小于10 小于10 update_max_sc() 小于10 小于10 小于10 小于10 update_ip_num() 小于10 小于10 小于10 小于10 insert_top_ten() 小于10 小于10 小于10 小于10 heap_adjust() 小于10 小于10 小于10 小于10 其他代码 39395 39086 54410 48099 总耗时 180699 232653 235521 240491
表2主要函数运行次数
函数名(次数) 第一批 第二批 第三批 第四批 get_userid() 13498152 15346753 14668286 14059765 count_net() 1885952 2377368 2317642 2342265 update_max_area() 1 1 1 1 Insert_hourflow() 1 1 1 1 update_max_sc() 1 1 1 1 update_ip_num() 1 1 1 1 insert_top_ten() 1 1 1 1 heap_adjust() 247 321 276 229 数据条数 13498152 15346753 14668286 14059765 由表1和表2可以看出，第一次数据处理中共统计出13498152条记录，其中有1885952用户匹配成功，其他数据不在监控范围内，因此被get_userid()函数过滤掉，count_net()函数被调用了1885952次，耗时54571ms，数据库插入函数仅仅被调用了一次，耗时非常小，可以被忽略掉。表1第一批数据总体耗时为180699ms，用户过滤模块耗时较多，达到86733ms，接近50%。因为每条记录均要过滤，所以耗时较多，其他代码耗时39395ms。其他代码耗时主要表现在程序环境初始化、读取离线数据文件、调用存储过程等。在表2可以分析得知，四次数据处理数据文件整体记录数大致在一千五百万左右。用户匹配成功以后的数据调用count_net()函数处理的记录数大概在二百万左右。分析表1可知，程序主要耗时在get_userid()和count_net()，这两个函数分别为用户过滤模块和数据处理模块。另外由表1可得第一批数据处理耗时比第二、三、四批数据少，因为第一批数据条数较少。还可以分析到，处理响应时间在第一批到第四批的整个过程略微有些增长。此现象是正常的，因为数据库在第一批处理过程中是空的，随着记录的增多数据库表中记录会增长。
根据上面的分析我们可以看出，系统满足对记录数据处理的响应速度。处理千万级数据，耗时仅仅为三到五分钟，因此该数据处理过程满足需求。
