使用DProf测定程序执行效率

代码写多了，程序就会变得臃肿；程序臃肿了，就会变慢。这时提高代码执行效率就非常重要了。但是，代码优化并不是几条best practice就能完成的。那些无关痛痒的空间分配、减少复制等优化措施，虽然有效，但却微乎其微。优化的关键，是要找出瓶颈并解决之，这样才能以最小的代价获得最佳的效果。 这就用到Perl的一个强大的工具：DProf。它可以测定程序执行的每个函数所花费的时间，通过它，你可以迅速找到瓶颈在什么地方，再对症下药。 最近我做的一次性能分析是这样的。我们的系统在某种条件下发送邮件时特别慢，甚至等待十几分钟也无法结束。究竟问题出在哪里却不得而知。于是DProf上场了。 首先写了个脚本，专门调用发送邮件的功能，排除其他功能的影响。然后运行命令： $ perl -d:DProf ./sendmail.pl 运行结束之后，会在当前目录下生成一个tmon.out文件。使用dprofpp即可查看统计信息： $ dprofpp Total Elapsed Time = 19.70195 Seconds User+System Time = 18.52195 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 83.5 15.46 15.770 11 1.4059 1.4337 Foo::Bar::crypt 9.34 1.730 1.730 2 0.8650 0.8650 Net::Cmd::datasend 1.24 0.230 0.305 17459 0.0000 0.0000 Crypt::Blowfish::encrypt 0.70 0.129 0.818 36 0.0036 0.0227 base::import 0.59 0.110 0.709 24 0.0046 0.0296 Foo::Bar::FooBarList::BEGIN 0.44 0.082 0.082 9108 0.0000 0.0000 IO::Wrap::read 0.40 0.075 0.075 17647 0.0000 0.0000 Crypt::Blowfish::crypt 0.27 0.050 0.887 7 0.0071 0.1268 main::BEGIN 统计信息的意思分别是： * ExclSec: 函数自身的执行时间（不包括函数调用的其他函数） * CumulS: 函数的执行时间（包括函数调用的其他函数） * #Calls: 调用次数 * sec/call: ExceSec/#Calls * Csec/c: CumulS/#Calls * Name: 函数名称 从上面的统计信息中可以看出，Foo::Bar::crypt占用了最多的时间(83.5%)。而且更为重要的信息是，CumulS - ExclSec = 15.770 - 15.46 = 0.31，也就是说，绝大部分时间都耗在了 Foo::Bar::crypt 函数本身，而不是它调用的其他函数。这样，只需针对Foo::Bar::crypt函数进行分析就可以了。 还可以使用另一个性能测试工具Devel::SmallProf。