Python 優化第一步: 性能分析實踐
前言
We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil. – Donald Knuth
先扔上一句名言來鎮樓。
當我們的確是有需要開始真正優化我們的Python程序的時候，我們要做的第一步并不是盲目的去做優化，而是對我們現有的程序進行分析，發現程序的性能瓶頸進而進行針對性的優化。這樣才會使我們花時間和精力去做的優化獲得最大的效果。
本文主要介紹Python內置的性能分析器的優雅使用方法，并以作者的一個化學動力學的程序為例子進行性能分析實踐, 介紹了常用的性能分析可視化工具的使用，最后對Python程序進行初步的性能優化嘗試。
正文
關于性能分析
性能分析就是分析代碼和正在使用的資源之間有著怎樣的聯系，它可以幫助我們分析運行時間從而找到程序運行的瓶頸，也可以幫助我們分析內存的使用防止內存泄漏的發生。
幫助我們進行性能分析的工具便是性能分析器，它主要分為兩類：
- 基于事件的性能分析(event-based profiling)
- 統計式的性能分析(statistical profiling)
Python的性能分析器
Python中最常用的性能分析工具主要有：cProfiler, line_profiler以及memory_profiler等。他們以不同的方式幫助我們分析Python代碼的性能。我們這里主要關注Python內置的cProfiler，并使用它幫助我們分析并優化程序。
cProfiler
快速使用
這里我先拿上官方文檔的一個簡單例子來對cProfiler的簡單使用進行簡單介紹。
import cProfile
import re
cProfile.run('re.compile("foo|bar")')
分析結果：
197 function calls (192 primitivecalls) in 0.002 seconds
Orderedby: standardname
ncalls tottime percall cumtime percallfilename: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個是原生調用（即不涉及遞歸調用）
- 總共執行的時間為0.002秒
- 結果列表中是按照標準名稱進行排序，也就是按照字符串的打印方式（數字也當作字符串）
- 在列表中：
- ncalls 表示函數調用的次數（有兩個數值表示有遞歸調用，總調用次數/原生調用次數）
- tottime 是函數內部調用時間（不包括他自己調用的其他函數的時間）
- percall 等于 tottime / ncalls
- cumtime 累積調用時間，與tottime相反，它包含了自己內部調用函數的時間
- 最后一列，文件名，行號，函數名
優雅的使用
Python給我們提供了很多接口方便我們能夠靈活的進行性能分析，其中主要包含兩個類cProfile模塊的 Profile 類和pstat模塊的 Stats 類。
我們可以通過這兩個類來將代碼分析的功能進行封裝以便在項目的其他地方能夠靈活重復的使用進行分析。
這里還是需要對 Profile 以及 Stats 的幾個常用接口進行簡單總結：
Profile 類:
- enable() : 開始收集性能分析數據
- disable() : 停止收集性能分析數據
- create_stats() : 停止收集分析數據，并為已收集的數據創建 stats 對象
- print_stats() : 創建stats對象并打印分析結果
- dump_stats(filename) : 把當前性能分析的結果寫入文件(二進制格式)
- runcall(func, *args, **kwargs) : 收集被調用函數 func 的性能分析數據 Stats 類
pstats模塊提供的 Stats 類可以幫助我們讀取和操作stats文件（二進制格式）
import pstats
p = pstats.Stats('stats.prof')
- Stats 類可以接受stats文件名，也可以直接接受 cProfile.Profile 對象作為數據源。
- strip_dirs() : 刪除報告中所有函數文件名的路徑信息
- dump_stats(filename) : 把stats中的分析數據寫入文件（效果同 cProfile.Profile.dump_stats() )
- sort_stats(*keys) : 對報告列表進行排序，函數會依次按照傳入的參數排序，關鍵詞包括 calls , cumtime 等，
- reverse_order() : 逆反當前的排序
- print_stats(*restrictions) : 把信息打印到標準輸出。 *restrictions 用于控制打印結果的形式, 例如 (10, 1.0, ".*.py.*") 表示打印所有py文件的信息的前10行結果。
有了上面的接口我們便可以更 優雅 的去使用分析器來分析我們的程序，例如可以通過寫一個 帶有參數的裝飾器 ，這樣想分析項目中任何一個函數，便可方便的使用裝飾器來達到目的。
import cProfile import pstats import os性能分析裝飾器定義
def do_cprofile(filename): """ Decorator for function profiling. """ def wrapper(func): def profiled_func(args, **kwargs): # Flag for do profiling or not. DO_PROF = os.getenv("PROFILING") if DO_PROF: profile = cProfile.Profile() profile.enable() result = func(args, kwargs) profile.disable() # Sort stat by internal time. sortby = "tottime" ps = pstats.Stats(profile).sort_stats(sortby) ps.dump_stats(filename) else: result = func(*args, kwargs) return result return profiled_func return wrapper </code></pre>
這樣我們可以在我們想進行分析的地方進行性能分析, 例如我想分析我的 MicroKineticModel 類中的 run 方法：
class MicroKineticModel(km.KineticModel): # ... # 應用裝飾器來分析函數 @do_cprofile("./mkm_run.prof") def run(self, **kwargs): # ...裝飾器函數中通過 sys.getenv 來獲取環境變量判斷是否需要進行分析，因此可以通過設置環境變量來告訴程序是否進行性能分析:
exportPROFILING=yrun the program...
</code></pre>
程序跑完后便會在當前路徑下生成mkm_run.prof的分析文件，我們便可以通過打印或者可視化工具來對這個函數進行分析。
性能分析實踐
下面我就通過分析自己的動力學程序中 MicroKineticModel 類中的方法來進行實踐，并使用常用的幾種性能分析可視化工具來幫助分析并進行初步的優化和效率對比。
注： 本次測試的程序主要包含數值求解微分方程以及牛頓法求解多元非線性方程組的求解，其中程序中的公式推導部分全部通過字符串操作完成。
生成性能分析報告
按照上文的方法，我們通過裝飾器對 run 方法進行修飾來進行性能分析，這樣我們便可以像正常一樣去跑程序，但是不同的是當前路徑下會生成性能分析報告文件。
# 設置環境變量 exportPROFILING=y執行運行腳本
pythonrun.py </code></pre>
在看似正常的運行之后，在當前路徑下我們會生成一個分析報告, mkm_run.prof , 它是一個二進制文件，我們需要用python的pstats模塊的接口來讀取。
我們只按照累積時間進行降序排序并輸出了前十行，整個函數只運行了0.106秒。可見程序大部分時間主要花在牛頓法求解的過程中，其中獲取解析Jacobian Matrix的過程是一個主要耗時的部分。
雖然我們可以通過命令行查看函數調用關系，但是我并不想花時間在反人類的黑白框中繼續分析程序，下面我打算上直觀的可視化工具了。
分析數據可視化
gprof2dot
Gprof2Dot可將多種Profiler的數據轉成Graphviz可處理的圖像表述。配合dot命令，即可得到不同函數所消耗的時間分析圖。
因此我們可以利用它來為我們的程序生成分析圖:
gprof2dot -f pstatsmkm_run.prof | dot -Tpng -o mkm_run.png于是我們路徑下面就生成了mkm_run.png
我倒是蠻喜歡這個時間分析圖，順著淺色方格的看下去很容易發現程序的瓶頸部分，
每個node的信息如下:
+------------------------------+ | functionname | | totaltime % ( self time % ) | | totalcalls | +------------------------------+每個edge的信息如下:
totaltime % calls parent --------------------> childrenvprof
也是一個不錯的工具來提供交互式的分析數據可視化，詳情參見: https://github.com/nvdv/vprof
他是針對文件進行執行并分析，并在瀏覽器中生成可視化圖標
# 生成CPU flame圖 vprof -c c run.py
RunSnakeRun
RunSnakeRun是另一個可對性能分析結果進行可視化的工具，它使用wxPython講Profiler的數據可視化
runsnakemkm_run.prof效果圖:
KCacheGrind & pyprof2calltree
KCacheGrind是Linux中常用的分析數據可視化軟件，他默認處理valgrind的輸出，但是我們結合 pyprof2calltree 工具可以把cProfile的輸出轉換成KCacheGrind支持的格式。
pyprof2calltree -i mkm_run.prof -k # 轉換格式并立即運行KCacheGrind
初步優化
通過直觀的可視化工具我們可以迅速找到程序中可以優化的部分，
可以看到我們在求解Jacobian矩陣的時候，會調用很多次求導函數，并且占據了比較大的時間，于是我們可以嘗試通過 函數返回值緩存 的方式進行初步優化。
為了能將函數的返回值進行緩存，我們添加了一個描述符:
class Memoized(object): def __init__(self, func): self.func = func self.results = {} def __get__(self, instance, cls): self.instance = instance return self def __call__(self, *args): key = args try: return self.results[key] except KeyError: self.results[key] = self.func(self.instance, *args) return self.results[key]這樣，在我們需要進行返回值緩存的函數上面使用此描述符，便可以將返回值緩存到描述符對象中，當我們使用相同參數進行重復調用時候，便可以直接返回數值，復雜度將為O(1)。
@Memoized def poly_adsorbate_derivation(self, adsorbate_name, poly_expression): # ...優化后我們再來進行一次分析:
同一個函數，運行時間從 0.106秒 降到了 0.061 秒效率提升近了 40%!
看一下函數調用關系圖:
而且函數調用次數明顯減少了，可以看到 poly_adsorbate_derivation 的調用次數從36次降到了9次， __total_term_adsorbate_derivation 從192次降到了48次。
總結
本文對Python內置的性能分析器cProfile的使用進行了介紹，并以作者項目中的代碼為例進行了實例分析和數據可視化，并使用了緩存的方式對Python程序進行了初步的優化，希望能借此幫助大家熟悉工具并分析自己Python程序性能的瓶頸寫出更好更高效的Python程序。
來自：http://python.jobbole.com/87621/