应用python的性能测量工具cProfile

cProfile的命令行用法

python -m cProfile XXX.py

输出到指定的文件：

python -m cProfile -o log.txt XXX.py

输出就被定向到了log.txt文件。

log.txt文件可以用VPT（http://visualpytune.googlecode.com）这样的图形工具打开。当log比较多的时候，可以很方便的进行过滤和时间的排序。

简单说一下log输出的阅读说明：

         2145 function calls (2058 primitive calls) in 0.301 seconds
 
    Ordered by: standard name
 
    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
         1    0.000    0.000    0.000    0.000 _strptime.py:103(__calc_am_pm)
         1    0.000    0.000    0.000    0.000 _strptime.py:115(__calc_date_time)
         1    0.022    0.022    0.024    0.024 _strptime.py:12(<module>)
         1    0.000    0.000    0.000    0.000 _strptime.py:160(__calc_timezone)
         1    0.000    0.000    0.000    0.000 _strptime.py:176(TimeRE)
         1    0.000    0.000    0.002    0.002 _strptime.py:179(__init__)
         4    0.000    0.000    0.000    0.000 _strptime.py:212(<genexpr>)
         6    0.000    0.000    0.000    0.000 _strptime.py:221(__seqToRE)
        49    0.000    0.000    0.000    0.000 _strptime.py:236(<genexpr>)
         4    0.000    0.000    0.001    0.000 _strptime.py:240(pattern)
         1    0.000    0.000    0.001    0.001 _strptime.py:263(compile)

输出如上图，主要有：

ncalls:  函数被call的次数
tottime：函数总的耗时，但是不包括其子函数的耗时
percall：tottime平均到每次调用的耗时
cumtime：函数总的耗时，包括了其子函数的耗时（递归函数也不例外）
percall：cumtime平均到每次调用的耗时
filename:lineno(function) ：每个函数各自的信息

cProfile在python代码中使用

import cProfile

cProfile.run('myfunction(arg1,arg2)', 'myfunction_prof')

使用以上的代码来引入cProfile, 并且使用其作为入口来调用待测函数。结果会放在myfunction_prof文件中。

这里再介绍一下结果文件在python下的阅读方法：

import pstats
p = pstats.Stats('myfunction_prof')

pstats还有排序，筛选等方法，便于阅读。

以上的内容，很容易在python的reference中找到，请参考：

http://docs.python.org/2/library/profile.html