听诊器是一种简单工具,却给医生的工作带来了革命:它让内科医生能有效地监控病人的身体。性能监视工具(profiler)对程序起着同样的作用。
你现在用什么工具来研究程序?复杂的分析系统很多,既有交互式调试器,又有程序动画系统。正如CT扫描仪永远代替不了听诊器一样,复杂的软件也永远代替不了程序员用来监控程序的最简单工具——性能监视工具,我们用它了解程序各部分的执行频率。
本文先用两种性能监视工具来加速一个小程序(记住真正的目的是说明性能监视工具)。后续各节简要介绍性能监视工具的各种用途、非过程语言的性能监视工具,以及开发性能监视工具的技术。
程序P1是个ANSI标准C程序,依次打印所有小于1000的素数。
程序P1
int prime(int n)
{ int i;
999 for (i = 2; i < n; i++)
78022 if(n%i == 0)
831 return 0;
168 return 1;
}
main()
{ int i, n;
1 n = 1000;
1 for (i = 2; i <= n; i++)
999 if (prime(i))
168 printf("%dn", i);
}
如果整型参数n是素数,上述prime函数返回1(真),否则返回0。这个函数检验2到n-1之间的所有整数,看其是否整除n。上述main过程用prime子程序来依次检查整数2~1000,发现素数就打印出来。
我像写任何一个C程序那样写好程序P1,然后在性能监视选项下进行编译。在程序运行之后,只要一个简单的命令就生成了前面所示的列表。(我稍微改变了一些输出的格式。)每行左侧的数由性能监视工具生成,用于说明相应的行执行了多少次。例如,main函数调用了1次,其中测试了999个整数,找出了168个素数。函数prime被调用了999次,其中168次返回1,另外831次返回0(快速验证:168+ 831=999)。prime函数共测试了78022个可能的因子,或者说为了确定素数性,对每个整数检查了大约78个因子。
程序P1是正确的,但是很慢。在VAX-11/750上,计算出小于1000的所有素数约需几秒钟,但计算出小于10 000的所有素数却需要3分钟。对这些计算的性能监视表明,大多数时间花在了测试因子上。因而下一个程序只对n考虑不超过sqrt n 的可能的整数因子。整型函数root先把整型参数转换成浮点型,然后调用库函数sqrt,最后再把浮点型结果转换回整型。程序P2包含两个旧函数和这个新函数root。
程序P2
int root(int n)
5456 { return (int) sqrt((float) n); }
int prime(int n)
{ int i;
999 for (i = 2; i < = root(n); i++)
5288 if (n % i == 0)
831 return 0;
168 return 1;
}
main()
{ int i, n;
1 n = 1000;
1 for (i = 2; i < = n; i++)
999 if (prime(i))
168 printf("%dn", i);
}
修改显然是有效的:程序P2的行计数显示,只测试了5288个因子(程序P1的1/14),总共调用了5456次root(测试了5288次整除性,168次由于i超出了root(n)而终止循环)。不过,虽然计数大大减少了,但是程序P2运行了5.8秒,而程序P1只运行了2.4秒(本节末尾的表中含有运行时间的更多细节)。这说明什么呢?
迄今为止,我们只看到了行计数(line-count)性能监视。过程时间(procedure-time)性能监视给出了较少的控制流细节,但更多地揭示了CPU时间:
%time cumsecs #call ms/call name
82.7 4.77 _sqrt
4.5 5.03 999 0.26 _prime
4.3 5.28 5456 0.05 _root
2.6 5.43 _frexp
1.4 5.51 _ _doprnt
1.2 5.57 _write
0.9 5.63 mcount
0.6 5.66 _creat
0.6 5.69 _printf
0.4 5.72 1 25.00 _main
0.3 5.73 _close
0.3 5.75 _exit
0.3 5.77 _isatty
过程按照运行时间递减的顺序列出。时间上既显示出总秒数,也显示出占总时间的百分比。编译后记录下源程序中main、prime和root这3个过程的调用次数。再次看到这几个计数是令人鼓舞的。其他过程没有性能监视的库函数,完成各种输入/输出和清理维护工作。第4列说明了带语句计数的所有函数每次调用的平均毫秒数。
过程时间性能监视说明,sqrt占用CPU时间的最多:该函数共被调用5456次,for循环的每次测试都要调用一次sqrt。程序P3通过把sqrt调用移到循环之外,使得在prime的每次调用中只调用一次费时的sqrt过程。
程序P3
int prime(int n)
{ int i, bound;
999 bound = root(n);
999 for (i = 2; i < = bound; i++)
5288 if (n % i == 0)
831 return 0;
168 return 1;
}
当n=1000时,程序P3的运行速度大约是程序P2的4倍,而当n= 100 000时则超过10倍。以n= 100 000的情形为例,过程时间性能监视显示,sqrt占用了程序P2的88%的运行时间,但是只占用了程序P3的48%的运行时间。这好多了,但仍然是循环的累赘。
程序P4合并了另外两个加速措施。首先,程序P4通过对被2、3和5整除的特殊检验,避免了近3/4的开方运算。语句计数表明,被2整除的性质大约把一半的输入归入合数,被3整除把剩余输入的1/3归入合数,被5整除再把剩下的这些数的1/5归入合数。其次,只考虑奇数作为可能的因子,在剩余的数中避免了大约一半的整除检验。它比程序P3大约快两倍,但是也比P3的错误更多。下面是(带错的)程序P4,你能通过检查语句计数看出问题吗?
程序P4
int root(int n)
265 { return (int) sqrt((float) n); }
int prime(int n)
{ int i, bound;
999 if (n % 2 == 0)
500 return 0;
499 if (n % 3 == 0)
167 return 0;
332 if (n % 5 == 0)
67 return 0;
265 bound = root(n);
265 for (i = 7; i <= bound; i = i+2)
1530 if (n % i == 0)
100 return 0;
165 return 1;
}
main()
{ int i, n;
1 n = 1000;
1 for (i = 2; i <= n; i++)
999 if (prime(i))
165 printf("%dn", i);
}
先前的程序找到168个素数,而程序P4只找到165个。丢失的3个素数在哪里?对了,我把3个数作为特殊情形,每个数都引入了一处错误:prime报告2不是素数,因为它被2整除。对于3和5,存在类似的错误。正确的检验是
if (n % 2 == 0)
return (n == 2);
依此类推。如果n被2整除,如果n是2就返回1,否则返回0。对于n=1000、10 000和100 000,程序P4的过程时间性能监视结果总结在下表中。
程序P5比程序P4快,并且有个好处:正确。它把费时的开方运算换成了乘法,如以下程序片段所示。
程序P5的片段
265 for (i = 7; i*i <= n; i = i+2)
1530 if (n % i == 0)
100 return 0;
165 return 1;
它还加入了对被2、3、5整除的正确检验。程序P5总的加速大约有20%。
最后的程序只对已被判定为素数的整数检验整除性;程序P6在1.4节,用Awk语言写成。C实现的过程时间性能监视结果表明,在n=1 000时,49%的运行时间花在prime和main上(其余是输入/输出);而当n=100 000时,88%的运行时间花在这两个过程上。
下面这个表总结了我们已经看到的这几个程序。表中还包含另外两个程序作为测试基准。程序Q1用习题答案2中的埃氏筛法程序计算素数。程序Q2测量输入/输出开销。对于n=1 000,它打印整数1, 2,…, 168;对于一般的n,它打印整数1, 2,…, P(n),其中P(n)是比n小的素数的个数。
以上集中讲述了性能监视的一种用途:当你调优单个子过程或函数的性能时,性能监视工具能告诉你运行时间都花在了哪里。
对于小程序来说,性能监视很容易实现,因此性能监视工具是可有可无的;但是对于开发大软件来说,性能监视工具则是不可或缺的。Brian Kernighan曾经使用行计数性能监视工具,研究了一个用于解释Awk语言程序的4000行的C程序。那时这个Awk解释程序已广泛使用了多年。扫描该程序75页长的程序清单就会发现,大多数计数都是成百上千的,有些甚至上万。一段晦涩的初始化代码,计数接近百万。Kernighan对一个6行的循环做了几处修改,程序速度就提高了一倍。他自己可能永远也猜不出程序的问题源头所在,但是性能监视工具引导他找到了。
Kernighan的这一经历是相当典型的。“一个程序中不到4%的语句通常占用了一半以上的运行时间。”对许多语言和系统的大量研究表明,对于不处理I/O密集型的大多数程序,大部分的运行时间花在了很小一部分代码上。这种模式是下述经验的基础:
Knuth在论文中描述了用行计数性能监视工具进行自我分析的结果。性能监视结果表明,一半的运行时间花在了两个循环上。结果花了不到一小时修改了几行代码,就让这个性能监视工具的速度提高了一倍。
性能监视结果说明,一个1000行的程序把80%的时间花在一个5行的子程序上。把这个子程序改写成十几行,就让程序的速度提高了一倍。
1984年贝尔实验室的Tom Szymanski打算给一个大系统提速,结果却使该系统慢了10%。他删除了修改的部分,然后多打开了一些性能监视选项以查明失败原因。他发现占用的存储空间增加到了原来的20倍,行计数显示存储空间的分配次数远多于释放次数。接下来用一条指令就纠正了错误,正确的实现让系统加速了一倍。
性能监视表明,操作系统一半的时间花在一个只有少数几条指令的循环上。改写微代码中的这个循环带来一个量级的提速,但是系统的吞吐量不变:性能组已经优化了系统的空闲循环!
这些经历引出了上一节粗略提到过的一个问题:应当在什么输入上监视程序的性能?查找素数的程序只有一个输入n,该输入强烈影响到时间性能监视:对于小的n,输入/输出占大头;对于大的n,计算占大头。有的程序的性能监视结果对输入数据非常不敏感。我猜想大多数计算薪水的程序都有相当一致的性能监视结果,至少从2月到11月如此。但有的程序的性能监视结果会随输入不同有巨大变化。难道你从没有察觉到,你的系统被调整得在制造商的基准数据上运行起来风驰电掣,而处理起你的重要任务时却慢如蜗牛?仔细挑选你的输入数据吧。
性能监视工具对于性能之外的任务也有用。在找素数的练习中,它指出了程序P4的一个错误。行计数在估计测试覆盖面时极有价值,比如,如果出现零,则说明有代码未测试。DEC公司的Dick Sites这样描述性能监视的其他用途:“(1) 在两层微存储实现中,决定哪些微代码放到芯片上;(2) 贝尔北方研究院(Bell Northern Research)的一位朋友某个周末在带有多重异步任务的实时电话交换软件系统上实现了语句计数。通过查看异常计数,他发现了现场安装的代码中存在6处错误,所有错误都涉及不同任务之间的交互。其中一处错误用常规调试技术无法成功追踪到,其余错误还没有被当作问题(也就是说,这些错误症状可能已经发生,但是没有人能够将其归结为具体的软件错误)。”
到目前为止我们所看到的性能监视工具的原理,适用于从汇编和Fortran直到Ada这样的程序设计语言,但是很多程序员现在使用更强大的语言。如何监视Lisp或APL程序的计算性能?又如何监视网络或数据库语言程序的计算性能?
我们打算用UNIX的管道(pipeline)作为更有趣的计算模型的例子。管道是一系列的过滤程序(filter):当数据流经每个过滤程序时,对数据施加变换。下面这个经典的管道按照频率递减顺序打印某文件中使用最多的25个单词。
cat $* ¦
tr -cs A-Za-z '