Python脚本性能剖析

jopen 10年前
###################
#Python脚本性能剖析
###################

cProfile/profile/hotshot用于统计Python脚本各部分执行频率和耗费时间等统计信息，pstats可用于格式化这些信息

cProfile，属C扩展，开销较小，适合剖析长时间运行的Python程序，推荐使用此模块
profile，纯Python模块，存在明显开销，但想对其扩展的话相对比较容易
hotshot，实验性的C模块，主要关注开销最小化，现已不再被维护将来可能从Python移除
profile和cProfile接口相同，cProfile相对较新可能在某些平台上不可用

以cProfile为例来说明Python脚本性能剖析方法
*以命令行方式使用：
$ python -m cProfile [-o output_file] [-s sort_order] myscript.py
例如：
$ python -m cProfile -o myscript.out myscript.py
之后使用pstats对结果进行格式化：
$ python -c "import pstats; p=pstats.Stats('myscript.out'); p.print_stats()"
可以在格式化时指定排序字段：
$ python -c "import pstats; p=pstats.Stats('myscript.out'); p.sort_stats('time').print_stats()"


*直接在脚本内部使用：
import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')

import pstats
p = pstats.Stats('restats')
#strip_dirs()移除模块名之前的路径信息，sort_stats(-1)按标准名(module/line/name)排序,print_stats打印统计信息
p.strip_dirs().sort_stats(-1).print_stats()
#按time排序并显示前10行
p.sort_stats('time').print_stats(10)
#按file排序只显示class init方法相关的统计信息
p.sort_stats('file').print_stats('__init__')
#先按time排序再按cum排序，只输出50%，然后仅列出包含init的部分
p.sort_stats('time', 'cum').print_stats(.5, 'init')
#若想知道谁调用了上述函数可以使用
p.print_callers(.5, 'init')

*cProfile模块说明
函数：
cProfile.run(command, filename=None, sort=-1)
cProfile.runctx(command, globals, locals, filename=None)¶
类：
cProfile.Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)
cProfile.Profile类下的方法：
enable()
Start collecting profiling data.

disable()
Stop collecting profiling data.

create_stats()
Stop collecting profiling data and record the results internally as the current profile.

print_stats(sort=-1)
Create a Stats object based on the current profile and print the results to stdout.

dump_stats(filename)
Write the results of the current profile to filename.

run(cmd)
Profile the cmd via exec().

runctx(cmd, globals, locals)
Profile the cmd via exec() with the specified global and local environment.

runcall(func, *args, **kwargs)
Profile func(*args, **kwargs)

*Stats类（pstats.Stats）说明
strip_dirs()    用以除去文件名前的路径信息。
add(filename,[…]) 把profile的输出文件加入Stats实例中统计
dump_stats(filename) 把Stats的统计结果保存到文件
sort_stats(key,[…]) 最重要的一个函数，用以排序profile的输出
reverse_order() 把Stats实例里的数据反序重排
print_stats([restriction,…]) 把Stats报表输出到stdout
print_callers([restriction,…]) 输出调用了指定的函数的函数的相关信息
print_callees([restriction,…]) 输出指定的函数调用过的函数的相关信息

sort_stats支持以下参数：

参数 含义

'calls' call count
'cumulative' cumulative time
'cumtime' cumulative time
'file' file name
'filename' file name
'module' file name
'ncalls' call count
'pcalls' primitive call count
'line' line number
'name' function name
'nfl' name/file/line
'stdname' standard name
'time' internal time
'tottime' internal time


*一个比较典型的输出结果：

   197 function calls (192 primitive calls) in 0.002 seconds
Ordered by: standard name
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 re.py:212(compile)
     1    0.000    0.000    0.001    0.001 re.py:268(_compile)
     1    0.000    0.000    0.000    0.000 sre_compile.py:172(_compile_charset)
     1    0.000    0.000    0.000    0.000 sre_compile.py:201(_optimize_charset)
     4    0.000    0.000    0.000    0.000 sre_compile.py:25(_identityfunction)
   3/1    0.000    0.000    0.000    0.000 sre_compile.py:33(_compile)

输出结果说明：

共有197次函数调用，原始调用为192次，原始调用说明不包含递归调用。
以standard name进行排序。3/1表示发生了递归调用，1为原始调用次数，3为递归调用次数
ncalls 函数的被调用次数
tottime 函数总计运行时间，除去函数中调用的函数运行时间
percall 函数运行一次的平均时间，等于tottime/ncalls
cumtime 函数总计运行时间，含调用的函数运行时间
percall 函数运行一次的平均时间，等于cumtime/ncalls
filename:lineno(function) 函数所在的文件名，函数的行号，函数名


参考：
https://docs.python.org/2/library/profile.html