Python程序调优 (Python Profiler)

概述

本文介绍基本的python profilter方法,并且用Openstack Nova作为例子展示具体使用方法。
本文介绍的profiler方法区别于一般常用的使用python cProfile模块,cProfile模块的分析结果不直观,并且仍然无法精确定位具体出问题代码。
本文的profile的最小粒度是“行”,profile的结果需要展示某行代码对CPU和memory的影响,最终帮助我们优化代码。

CPU Profiler

我们使用Robert Kern 写的 line_profiler 项目,安装
  1. $ pip install line_profiler 

会安装一个可执行文件“kernprof.py”。然后修改目标代码,只要在需要测试的函数加上@profile,不用import任何东西,只要加上这一句即可,因为kernprof会动态插入。

test.py
  1. @profile 
  2. def run(): 
  3.     a = [1]*100 
  4.     b = [x*x*x for x in a ] 
  5.     c = [x for x in b] 
  6.     d = c*2 
  7.  
  8. run() 
运行
  1. kernprof.py -l -v test.py 

-l表示动态插入profile.

-v 当程序运行结束后,将结果输出到标准输出,而不是到文件中。
其他用法可以参看kernprof帮助:kernprof –help。
结果很详细,给出了每行运行时间,百分比等:
  1. Wrote profile results to test.py.lprof 
  2. Timer unit: 1e-06 s 
  3.  
  4.  
  5. File: test.py 
  6. Function: run at line 1 
  7. Total time: 0.000322 s 
  8.  
  9.  
  10. Line #      Hits         Time  Per Hit   % Time  Line Contents 
  11. ============================================================== 
  12.      1                                           @profile 
  13.      2                                           def run(): 
  14.      3         1            5      5.0      1.6      a = [1]*100 
  15.      4       101          166      1.6     51.6      b = [x*x*x for x in a ] 
  16.      5       101          147      1.5     45.7      c = [x for x in b] 
  17.      6         1            4      4.0      1.2      d = c*2 

Memory Profiler

在line_profiler基础之上, fabian实现了针对行的memory profiler,安装:
  1. $ pip install -U memory_profiler 
  2. $ pip install psutil 

(psutil不是必须,但是安装上会提高memory_profiler的效率)

还是之前的那串代码,还是在目标函数上加上@profiler。运行:
  1. $ python -m memory_profiler test.py 
  1. Filename: test.py 
  2.  
  3. Line #    Mem usage    Increment   Line Contents 
  4. ================================================ 
  5.      1                             @profile 
  6.      2     9.488 MB     0.000 MB   def run(): 
  7.      3     9.496 MB     0.008 MB       a = [1]*100 
  8.      4     9.504 MB     0.008 MB       b = [x*x*x for x in a ] 
  9.      5     9.504 MB     0.000 MB       c = [x for x in b] 
  10.      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 
  1. @profile 
  2. def main(): 
  3.     config.parse_args([]) # 这里参数原本是sys.argv,因为parse_args()会修改sys.argv,导致memory_profiler不能正常执行,所以我决定不传sys.argv进去,既默认不带任何参数启动nova-compute。 
  4.     logging.setup(‘nova’
  5.     utils.monkey_patch() 
  6.  
  7.  
  8.     if not CONF.conductor.use_local: 
  9.         block_db_access() 
  10.  
  11.  
  12.     server = service.Service.create(binary=‘nova-compute’
  13.                                     topic=CONF.compute_topic, 
  14.                                     db_allowed=False
  15.     service.serve(server) 
  16.     service.wait() 

执行:

  1. kernprof.py -l -v bin/nova-compute 
  1. Wrote profile results to nova-compute.lprof 
  2. Timer unit: 1e-06 s 
  3.  
  4. File: /opt/stack/nova/nova/cmd/compute.py 
  5. Function: main at line 52 
  6. Total time: 80.6356 s 
  7.  
  8. Line #      Hits         Time  Per Hit   % Time  Line Contents 
  9. ============================================================== 
  10.     52                                           @profile 
  11.     53                                           def main(): 
  12.     54         1        15483  15483.0      0.0      config.parse_args(sys.argv) 
  13.     55         1         1859   1859.0      0.0      logging.setup(‘nova’) 
  14.     56         1           85     85.0      0.0      utils.monkey_patch() 
  15.     57                                            
  16.     58         1          132    132.0      0.0      if not CONF.conductor.use_local: 
  17.     59         1           88     88.0      0.0          block_db_access() 
  18.     60                                            
  19.     61         1            4      4.0      0.0      server = service.Service.create(binary=’nova-compute’, 
  20.     62         1          106    106.0      0.0                                      topic=CONF.compute_topic, 
  21.     63         1     51468528 51468528.0     63.8                                      db_allowed=False) 
  22.     64         1          205    205.0      0.0      service.serve(server) 
  23.     65         1     29149130 29149130.0     36.1      service.wait() 
  1. $ python -m memory_profiler bin/nova-compute  
  1. Filename: nova/cmd/compute.py 
  2.  
  3. Line #    Mem usage    Increment   Line Contents 
  4. ================================================ 
  5.     52                             @profile 
  6.     53    32.883 MB     0.000 MB   def main(): 
  7.     54    33.027 MB     0.145 MB       config.parse_args([]) 
  8.     55    33.043 MB     0.016 MB       logging.setup(‘nova’) 
  9.     56    33.043 MB     0.000 MB       utils.monkey_patch() 
  10.     57                              
  11.     58    33.043 MB     0.000 MB       if not CONF.conductor.use_local: 
  12.     59    33.047 MB     0.004 MB           block_db_access() 
  13.     60                              
  14.     61    33.047 MB     0.000 MB       server = service.Service.create(binary=’nova-compute’, 
  15.     62    33.047 MB     0.000 MB                                       topic=CONF.compute_topic, 
  16.     63    47.371 MB    14.324 MB                                       db_allowed=False) 
  17.     64    47.371 MB     0.000 MB       service.serve(server) 
  18.     65    49.434 MB     2.062 MB       service.wait() 
由于分析结果要等进程结束退出之后才有,但是nova-compute是daemon进程,所以需要了解nova-compute进程执行到哪一步了。
根据日志输出,当nova开始执行periodic_task之后,基本可以认为这些代码都执行完成了。

本文介绍了line_profiler和memory_profiler的基本使用方法,有了这两个工具,可以轻松的分析任意函数的执行效率,“快准狠”。

References

http://www.huyng.com/posts/python-performance-analysis/

About 智足者富

http://chenpeng.info

发表评论

电子邮件地址不会被公开。 必填项已用*标注

您可以使用这些HTML标签和属性:

<a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>