记忆碎片

       昨天去席老师哪里论文格式审查，回来再次修改论文。这一段时间，忙的简直要抽风了，改论文，看论文，再改论文…总算差不多了。

       最近写论文的时候，第五章要写到一个测试，其中包括性能测试。本意是想测出系统中每个模块的性能，也就是每个模块运行次数以及运行时间。经过一番的百度和谷歌，最后决定使用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可得第一批数据处理耗时比第二、三、四批数据少，因为第一批数据条数较少。还可以分析到，处理响应时间在第一批到第四批的整个过程略微有些增长。此现象是正常的，因为数据库在第一批处理过程中是空的，随着记录的增多数据库表中记录会增长。

       根据上面的分析我们可以看出，系统满足对记录数据处理的响应速度。处理千万级数据，耗时仅仅为三到五分钟，因此该数据处理过程满足需求。