Python 性能分析入門指南

注： 本文的原做者是 Huy Nguyen ，原文地址爲 A guide to analyzing Python performance

雖然並不是你編寫的每一個 Python 程序都要求一個嚴格的性能分析，可是讓人放心的是，當問題發生的時候，Python 生態圈有各類各樣的工具能夠處理這類問題。

分析程序的性能能夠歸結爲回答四個基本問題：

1. 正運行的多快
2. 速度瓶頸在哪裏
3. 內存使用率是多少
4. 內存泄露在哪裏

下面，咱們將用一些神奇的工具深刻到這些問題的答案中去。

用 time 粗粒度的計算時間

讓咱們開始經過使用一個快速和粗暴的方法計算咱們的代碼:傳統的 unix time 工具。

$ time python yourprogram.py
real    0m1.028s
user    0m0.001s
sys     0m0.003s

三個輸出測量值之間的詳細意義在這裏 stackoverflow article，但簡介在這：

• real -- 指的是實際耗時
• user -- 指的是內核以外的 CPU 耗時
• sys -- 指的是花費在內核特定函數的 CPU 耗時

你會有你的應用程序用完了多少 CPU 週期的即視感，無論系統上其餘運行的程序添加的系統和用戶時間。

若是 sys 和 user 時間之和小於 real 時間，而後你能夠猜想到大多數程序的性能問題最有可能與 IO wait 相關。

用 timing context 管理器細粒度的計算時間

咱們下一步的技術包括直接嵌入代碼來獲取細粒度的計時信息。下面是我進行時間測量的代碼的一個小片斷

timer.py

import time

class 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

爲了使用它，使用 Python 的 with 關鍵字和 Timer 上下文管理器來包裝你想計算的代碼。當您的代碼塊開始執行，它將照顧啓動計時器,當你的代碼塊結束的時候，它將中止計時器。

這個代碼片斷示例：

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

爲了看看個人程序的性能隨着時間的演化的趨勢，我經常記錄這些定時器的輸出到一個文件中。

使用 profiler 逐行計時和分析執行的頻率

羅伯特·克恩有一個不錯的項目稱爲 line_profiler , 我常用它來分析個人腳本有多快，以及每行代碼執行的頻率：

爲了使用它，你能夠經過使用 pip 來安裝它：

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 s

File: 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

尋找 hits 值比較高的行或是一個高時間間隔。這些地方有最大的優化改進空間。

它使用了多少內存？

如今咱們掌握了很好咱們代碼的計時信息，讓咱們繼續找出咱們的程序使用了多少內存。咱們真是很是幸運， Fabian Pedregosa 仿照 Robert Kern 的 line_profiler 實現了一個很好的內存分析器 [memory profiler][5]。

首先經過 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.py

Line #    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]

line_profiler 和 memory_profiler 的 IPython 快捷命令

line_profiler 和 memory_profiler 一個不爲人知的特性就是在 IPython 上都有快捷命令。你所能作的就是在 IPython 上鍵入如下命令：

%load_ext memory_profiler
%load_ext line_profiler

這樣作了之後，你就可使用魔法命令 %lprun 和 %mprun 了，它們表現的像它們命令行的副本，最主要的不一樣就是你不須要給你須要分析的函數設置 @profile 修飾符。直接在你的 IPython 會話上繼續分析吧。

In [1]: from primes import primes
In [2]: %mprun -f primes primes(1000)
In [3]: %lprun -f primes primes(1000)

這能夠節省你大量的時間和精力,由於使用這些分析命令，你不須要修改你的源代碼。

哪裏內存溢出了？

cPython的解釋器使用引用計數來做爲它跟蹤內存的主要方法。這意味着每一個對象持有一個計數器，當增長某個對象的引用存儲的時候，計數器就會增長，當一個引用被刪除的時候，計數器就是減小。當計數器達到0， cPython 解釋器就知道該對象再也不使用，所以解釋器將刪除這個對象，而且釋放該對象持有的內存。

內存泄漏每每發生在即便該對象再也不使用的時候，你的程序還持有對該對象的引用。

最快速發現內存泄漏的方式就是使用一個由 Marius Gedminas 編寫的很是好的稱爲 [objgraph][6] 的工具。
這個工具可讓你看到在內存中對象的數量,也定位在代碼中全部不一樣的地方,對這些對象的引用。

開始，咱們首先安裝 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

哪一個對象被增長或是刪除了？

咱們能在兩個時間點之間看到哪些對象被增長或是刪除了。

(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() call

traceback                4        +2
KeyboardInterrupt        1        +1
frame                   24        +1
list                   667        +1
tuple                16969        +1

這個泄漏對象的引用是什麼？

繼續下去，咱們還能夠看到任何給定對象的引用在什麼地方。讓咱們如下面這個簡單的程序舉個例子。

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 程序內存的前 N 個對象
• 顯示在一段時期內哪些對象被增長了，哪些對象被刪除了
• 顯示咱們腳本中得到的全部引用

Effort vs precision

在這篇文章中,我展現瞭如何使用一些工具來分析一個python程序的性能。經過這些工具和技術的武裝，你應該能夠獲取全部要求追蹤大多數內存泄漏以及在Python程序快速識別瓶頸的信息。

和許多其餘主題同樣,運行性能分析意味着要在付出和精度之間的平衡作取捨。當有疑問是，用最簡單的方案，知足你當前的需求。

相關閱讀：

• stack overflow - time explained
• line_profiler
• memory_profiler
• objgraph