概述
本文介绍基本的python profilter方法,并且用Openstack Nova作为例子展示具体使用方法。
本文介绍的profiler方法区别于一般常用的使用python cProfile模块,cProfile模块的分析结果不直观,并且仍然无法精确定位具体出问题代码。
本文的profile的最小粒度是“行”,profile的结果需要展示某行代码对CPU和memory的影响,最终帮助我们优化代码。
CPU Profiler
我们使用Robert Kern 写的 line_profiler 项目,安装
2016年11月14日更新:
$ pip install 'line_profiler<2.0'
因为 line_profiler 2.0 之后依赖 IPython,我并不需要它,所以强制版本号。
会安装一个可执行文件“kernprof.py”。然后修改目标代码,只要在需要测试的函数加上@profile,不用import任何东西,只要加上这一句即可,因为kernprof会动态插入。
test.py
@profile
def run():
a = [1]*100
b = [x*x*x for x in a ]
c = [x for x in b]
d = c*2
run()
运行
2016年11月14日更新
kernperf -l -v test.py
-l表示动态插入profile.
-v 当程序运行结束后,将结果输出到标准输出,而不是到文件中。
其他用法可以参看kernprof帮助:kernprof –help。
结果很详细,给出了每行运行时间,百分比等:
Wrote profile results to test.py.lprof
Timer unit: 1e-06 s
File: test.py
Function: run at line 1
Total time: 0.000322 s
Line # Hits Time Per Hit % Time Line Contents
==============================================================
1 @profile
2 def run():
3 1 5 5.0 1.6 a = [1]*100
4 101 166 1.6 51.6 b = [x*x*x for x in a ]
5 101 147 1.5 45.7 c = [x for x in b]
6 1 4 4.0 1.2 d = c*2
Memory Profiler
在line_profiler基础之上, fabian实现了针对行的memory profiler,安装:
$ pip install -U memory_profiler
$ pip install psutil
(psutil不是必须,但是安装上会提高memory_profiler的效率)
还是之前的那串代码,还是在目标函数上加上@profiler。运行:
$ python -m memory_profiler test.py
Filename: test.py
Line # Mem usage Increment Line Contents
================================================
1 @profile
2 9.488 MB 0.000 MB def run():
3 9.496 MB 0.008 MB a = [1]*100
4 9.504 MB 0.008 MB b = [x*x*x for x in a ]
5 9.504 MB 0.000 MB c = [x for x in b]
6 9.504 MB 0.000 MB d = c*2
与之前的结果类似,给出了某行的内存的增量。
Profile Openstack Nova
本文用nova-compute举例,直接研究nova-compute最外层调用后,CPU使用情况和memory使用情况,如果读者有兴趣可以进一步分析,往更深层次的函数上加@profile。
实例代码是grizzly版本。
nova/cmd/compute.py
@profile
def main():
config.parse_args([]) # 这里参数原本是sys.argv,因为parse_args()会修改sys.argv,导致memory_profiler不能正常执行,所以我决定不传sys.argv进去,既默认不带任何参数启动nova-compute。
logging.setup('nova')
utils.monkey_patch()
if not CONF.conductor.use_local:
block_db_access()
server = service.Service.create(binary='nova-compute',
topic=CONF.compute_topic,
db_allowed=False)
service.serve(server)
service.wait()
执行:
kernprof.py -l -v bin/nova-compute
Wrote profile results to nova-compute.lprof
Timer unit: 1e-06 s
File: /opt/stack/nova/nova/cmd/compute.py
Function: main at line 52
Total time: 80.6356 s
Line # Hits Time Per Hit % Time Line Contents
==============================================================
52 @profile
53 def main():
54 1 15483 15483.0 0.0 config.parse_args(sys.argv)
55 1 1859 1859.0 0.0 logging.setup('nova')
56 1 85 85.0 0.0 utils.monkey_patch()
57
58 1 132 132.0 0.0 if not CONF.conductor.use_local:
59 1 88 88.0 0.0 block_db_access()
60
61 1 4 4.0 0.0 server = service.Service.create(binary='nova-compute',
62 1 106 106.0 0.0 topic=CONF.compute_topic,
63 1 51468528 51468528.0 63.8 db_allowed=False)
64 1 205 205.0 0.0 service.serve(server)
65 1 29149130 29149130.0 36.1 service.wait()
$ python -m memory_profiler bin/nova-compute
Filename: nova/cmd/compute.py
Line # Mem usage Increment Line Contents
================================================
52 @profile
53 32.883 MB 0.000 MB def main():
54 33.027 MB 0.145 MB config.parse_args([])
55 33.043 MB 0.016 MB logging.setup('nova')
56 33.043 MB 0.000 MB utils.monkey_patch()
57
58 33.043 MB 0.000 MB if not CONF.conductor.use_local:
59 33.047 MB 0.004 MB block_db_access()
60
61 33.047 MB 0.000 MB server = service.Service.create(binary='nova-compute',
62 33.047 MB 0.000 MB topic=CONF.compute_topic,
63 47.371 MB 14.324 MB db_allowed=False)
64 47.371 MB 0.000 MB service.serve(server)
65 49.434 MB 2.062 MB service.wait()
由于分析结果要等进程结束退出之后才有,但是nova-compute是daemon进程,所以需要了解nova-compute进程执行到哪一步了。
根据日志输出,当nova开始执行periodic_task之后,基本可以认为这些代码都执行完成了。
本文介绍了line_profiler和memory_profiler的基本使用方法,有了这两个工具,可以轻松的分析任意函数的执行效率,“快准狠”。
转载请注明:爱开源 » Python程序调优 (Python Profiler)