Python性能分析指南
盡管并非每個你寫的Python程序都需要嚴格的性能分析,但了解一下Python的生態系統中很多優秀的在你需要做性能分析的時候可以使用的工具仍然是一件值得去做的事。
分析一個程序的性能,最終都歸結為回答4個基本的問題:
- 程序運行速度有多快?
- 運行速度瓶頸在哪兒?
- 程序使用了多少內存?
- 內存泄露發生在哪里? </ol> 下面,我們將使用一些優秀的工具深入回答這些問題。
- real - 表示實際的程序運行時間
- user - 表示程序在用戶態的cpu總時間
- sys - 表示在內核態的cpu總時間 </ul>
- 顯示占據python程序內存的頭N個對象
- 顯示一段時間以后哪些對象被刪除活增加了
- 在我們的腳本中顯示某個給定對象的所有引用 </ul>
使用time工具粗糙定時
首先,我們可以使用快速然而粗糙的工具:古老的unix工具time,來為我們的代碼檢測運行時間。
$ time python yourprogram.pyreal 0m1.028s user 0m0.001s sys 0m0.003s</pre>上面三個輸入變量的意義在文章 stackoverflow article 中有詳細介紹。簡單的說:</span>
通過sys和user時間的求和,你可以直觀的得到系統上沒有其他程序運行時你的程序運行所需要的CPU周期。
若sys和user時間之和遠遠少于real時間,那么你可以猜測你的程序的主要性能問題很可能與IO等待相關。
使用計時上下文管理器進行細粒度計時
我們的下一個技術涉及訪問細粒度計時信息的直接代碼指令。這是一小段代碼,我發現使用專門的計時測量是非常重要的:
timer.py
import timeclass Timer(object): def init(self, verbose=False): self.verbose = verbose
def __enter__(self): self.start = time.time() return self def __exit__(self, *args): self.end = time.time() self.secs = self.end - self.start self.msecs = self.secs * 1000 # millisecs if self.verbose: print 'elapsed time: %f ms' % self.msecs</pre> <p>為了使用它,你需要用Python的with關鍵字和Timer上下文管理器包裝想要計時的代碼塊。它將會在你的代碼塊開始執行的時候啟動計時器,在你的代碼塊結束的時候停止計時器。 </p>這是一個使用上述代碼片段的例子:
from timer import Timer from redis import Redis rdb = Redis()with Timer() as t: rdb.lpush("foo", "bar") print "=> elasped lpush: %s s" % t.secs
with Timer as t: rdb.lpop("foo") print "=> elasped lpop: %s s" % t.secs</pre>
我經常將這些計時器的輸出記錄到文件中,這樣就可以觀察我的程序的性能如何隨著時間進化。
使用分析器逐行統計時間和執行頻率
Robert Kern有一個稱作line_profiler的不錯的項目,我經常使用它查看我的腳步中每行代碼多快多頻繁的被執行。
想要使用它,你需要通過pip安裝該python包:
$ pip install line_profiler一旦安裝完成,你將會使用一個稱做“line_profiler”的新模組和一個“kernprof.py”可執行腳本。
想要使用該工具,首先修改你的源代碼,在想要測量的函數上裝飾@profile裝飾器。不要擔心,你不需要導入任何模組。kernprof.py腳本將會在執行的時候將它自動地注入到你的腳步的運行時。
primes.py
@profile def primes(n): if n==2: return [2] elif n<2: return [] s=range(3,n+1,2) mroot = n ** 0.5 half=(n+1)/2-1 i=0 m=3 while m <= mroot: if s[i]: j=(m*m-3)/2 s[j]=0 while j<half: s[j]=0 j+=m i=i+1 m=2*i+3 return [2]+[x for x in s if x] primes(100)一旦你已經設置好了@profile裝飾器,使用kernprof.py執行你的腳步。$ kernprof.py -l -v fib.py-l選項通知kernprof注入@profile裝飾器到你的腳步的內建函數,-v選項通知kernprof在腳本執行完畢的時候顯示計時信息。上述腳本的輸出看起來像這樣:Wrote profile results to primes.py.lprof Timer unit: 1e-06 sFile: primes.py Function: primes at line 2 Total time: 0.00019 s
Line # Hits Time Per Hit % Time Line Contents
2 @profile 3 def primes(n): 4 1 2 2.0 1.1 if n==2: 5 return [2] 6 1 1 1.0 0.5 elif n<2: 7 return [] 8 1 4 4.0 2.1 s=range(3,n+1,2) 9 1 10 10.0 5.3 mroot = n ** 0.5 10 1 2 2.0 1.1 half=(n+1)/2-1 11 1 1 1.0 0.5 i=0 12 1 1 1.0 0.5 m=3 13 5 7 1.4 3.7 while m <= mroot: 14 4 4 1.0 2.1 if s[i]: 15 3 4 1.3 2.1 j=(m*m-3)/2 16 3 4 1.3 2.1 s[j]=0 17 31 31 1.0 16.3 while j<half: 18 28 28 1.0 14.7 s[j]=0 19 28 29 1.0 15.3 j+=m 20 4 4 1.0 2.1 i=i+1 21 4 4 1.0 2.1 m=2*i+3 22 50 54 1.1 28.4 return [2]+[x for x in s if x]</pre> <p>尋找具有高Hits值或高Time值的行。這些就是可以通過優化帶來最大改善的地方。 </p>程序使用了多少內存?
現在我們對計時有了較好的理解,那么讓我們繼續弄清楚程序使用了多少內存。我們很幸運,Fabian Pedregosa模仿Robert Kern的line_profiler實現了一個不錯的內存分析器。
首先使用pip安裝:
$ pip install -U memory_profiler $ pip install psutil(這里建議安裝psutil包,因為它可以大大改善memory_profiler的性能)。
就像line_profiler,memory_profiler也需要在感興趣的函數上面裝飾@profile裝飾器:
@profile def primes(n): ... ...想要觀察你的函數使用了多少內存,像下面這樣執行:$ python -m memory_profiler primes.py一旦程序退出,你將會看到看起來像這樣的輸出:Filename: primes.pyLine # Mem usage Increment Line Contents
2 @profile 3 7.9219 MB 0.0000 MB def primes(n): 4 7.9219 MB 0.0000 MB if n==2: 5 return [2] 6 7.9219 MB 0.0000 MB elif n<2: 7 return [] 8 7.9219 MB 0.0000 MB s=range(3,n+1,2) 9 7.9258 MB 0.0039 MB mroot = n ** 0.5 10 7.9258 MB 0.0000 MB half=(n+1)/2-1 11 7.9258 MB 0.0000 MB i=0 12 7.9258 MB 0.0000 MB m=3 13 7.9297 MB 0.0039 MB while m <= mroot: 14 7.9297 MB 0.0000 MB if s[i]: 15 7.9297 MB 0.0000 MB j=(m*m-3)/2 16 7.9258 MB -0.0039 MB s[j]=0 17 7.9297 MB 0.0039 MB while j<half: 18 7.9297 MB 0.0000 MB s[j]=0 19 7.9297 MB 0.0000 MB j+=m 20 7.9297 MB 0.0000 MB i=i+1 21 7.9297 MB 0.0000 MB m=2*i+3 22 7.9297 MB 0.0000 MB return [2]+[x for x in s if x]</pre> <h3>line_profiler和memory_profiler的IPython快捷方式 </h3>memory_profiler和line_profiler有一個鮮為人知的小竅門,兩者都有在IPython中的快捷命令。你需要做的就是在IPython會話中輸入以下內容:
%load_ext memory_profiler %load_ext line_profiler在這樣做的時候你需要訪問魔法命令%lprun和%mprun,它們的行為類似于他們的命令行形式。主要區別是你不需要使用@profiledecorator來修飾你要分析的函數。只需要在IPython會話中像先前一樣直接運行分析:
In [1]: from primes import primes In [2]: %mprun -f primes primes(1000) In [3]: %lprun -f primes primes(1000)這樣可以節省你很多時間和精力,因為你的源代碼不需要為使用這些分析命令而進行修改。
內存泄漏在哪里?
cPython解釋器使用引用計數做為記錄內存使用的主要方法。這意味著每個對象包含一個計數器,當某處對該對象的引用被存儲時計數器增加,當引用被刪除時計數器遞減。當計數器到達零時,cPython解釋器就知道該對象不再被使用,所以刪除對象,釋放占用的內存。
如果程序中不再被使用的對象的引用一直被占有,那么就經常發生內存泄漏。
查找這種“內存泄漏”最快的方式是使用Marius Gedminas編寫的objgraph,這是一個極好的工具。該工具允許你查看內存中對象的數量,定位含有該對象的引用的所有代碼的位置。
一開始,首先安裝objgraph:
pip install objgraph一旦你已經安裝了這個工具,在你的代碼中插入一行聲明調用調試器:import pdb; pdb.set_trace()最普遍的對象是哪些?
在運行的時候,你可以通過執行下述指令查看程序中前20個最普遍的對象:
(pdb) import objgraph (pdb) objgraph.show_most_common_types()MyBigFatObject 20000 tuple 16938 function 4310 dict 2790 wrapper_descriptor 1181 builtin_function_or_method 934 weakref 764 list 634 method_descriptor 507 getset_descriptor 451 type 439</pre>
哪些對象已經被添加或刪除?
我們也可以查看兩個時間點之間那些對象已經被添加或刪除:
(pdb) import objgraph (pdb) objgraph.show_growth() . . . (pdb) objgraph.show_growth() # this only shows objects that has been added or deleted since last show_growth() calltraceback 4 +2 KeyboardInterrupt 1 +1 frame 24 +1 list 667 +1 tuple 16969 +1</pre>
誰引用著泄漏的對象?
繼續,你還可以查看哪里包含給定對象的引用。讓我們以下述簡單的程序做為一個例子:
x = [1] y = [x, [x], {"a":x}] import pdb; pdb.set_trace()想要看看哪里包含變量x的引用,執行objgraph.show_backref()函數:(pdb) import objgraph (pdb) objgraph.show_backref([x], filename="/tmp/backrefs.png")該命令的輸出應該是一副PNG圖像,保存在/tmp/backrefs.png,它看起來是像這樣:
![]()
最下面有紅字的盒子是我們感興趣的對象。我們可以看到,它被符號x引用了一次,被列表y引用了三次。如果是x引起了一個內存泄漏,我們可以使用這個方法,通過跟蹤它的所有引用,來檢查為什么它沒有自動的被釋放。
回顧一下,objgraph 使我們可以:
努力與精度
在本帖中,我給你顯示了怎樣用幾個工具來分析python程序的性能。通過這些工具與技術的武裝,你可以獲得所有需要的信息,來跟蹤一個python程序中大多數的內存泄漏,以及識別出其速度瓶頸。
對許多其他觀點來說,運行一次性能分析就意味著在努力目標與事實精度之間做出平衡。如果感到困惑,那么就實現能適應你目前需求的最簡單的解決方案。