Python程式調優 (Python Profiler)

概述本文介紹基本的python profilter方法，並且用Openstack Nova作為例子展示具體使用方法。本文介紹的profiler方法區別於一般常用的使用python cProfile模組， cProfile模組的分析結果不直觀，並且仍然無法精確定位具體出問題代碼。本文的profile的最小粒度是“行”，profile的結果需要展示某行代碼對CPU和memory的影響，最終協助我們最佳化代碼。CPU Profiler我們使用Robert Kern 寫的 line_profiler 項目，安裝

$ pip install line_profiler

會安裝一個可執行檔“kernprof.py”。然後修改目標代碼，只要在需要測試的函數加上@profile，不用import任何東西，只要加上這一句即可，因為kernprof會動態插入。

test.py

@profiledef run():    a = [1]*100    b = [x*x*x for x in a ]    c = [x for x in b]    d = c*2run()

運行

kernprof.py -l -v test.py

-l表示動態插入profile.

-v 當程式運行結束後，將結果輸出到標準輸出，而不是到檔案中。其他用法可以參看kernprof協助：kernprof --help。結果很詳細，給出了每行已耗用時間，百分比等：

Wrote profile results to test.py.lprofTimer unit: 1e-06 sFile: test.pyFunction: run at line 1Total time: 0.000322 sLine #      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.pyLine #    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  

@profiledef 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.lprofTimer unit: 1e-06 sFile: /opt/stack/nova/nova/cmd/compute.pyFunction: main at line 52Total time: 80.6356 sLine #      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.pyLine #    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的基本使用方法，有了這兩個工具，可以輕鬆的分析任意函數的執行效率，“快准狠”。Referenceshttp://www.huyng.com/posts/python-performance-analysis/