Python的高效體現(xiàn)在它的開發(fā)效率，完善的類庫支持，特別是這幾年在數(shù)據(jù)科學中的流行，使得Python開始在各種語言排行榜獨占鰲頭，但是Python代碼運行效率低這一點也一直被詬病，要想讓Python高效運行，掌握一套性能分析的方法和工具，就顯得很重要。

一般通過profiling找到代碼瓶頸，然后針對這個瓶頸代碼進行優(yōu)化，從而可以到達事半功倍的效果，即用最少的工作量來獲得最大的性能的提升，這在任何場景下都是最優(yōu)的選擇。任何可衡量的資源都可以進行profiling，除了CPU，內(nèi)存還包括網(wǎng)絡帶寬，磁盤I/O。

profiling的目的就是通過對系統(tǒng)進行分析，找出哪里比較慢，哪里消耗內(nèi)存比較多，哪里會引起更多的磁盤I/O或者網(wǎng)絡I/O。但是profiling通常會增加代碼的額外開銷，這種開銷有時候是非常大，會10x甚至100x的降低代碼運行效率。所以profiling一般不能直接針對線上的代碼進行，一般是構(gòu)建一套類線上環(huán)境，或者把需要做profiling的代碼拿出來單獨進行分析。

Python常用的profiling方法：

Timing

最基礎的就是使用time.time()來計時，這個方法簡單有效，也許所有寫過Python代碼的人都用過。

import time
...
start_time = time.time()
output = foo(a, b, c)
end_time = time.time()
secs = end_time - start_time
print foo.func_name + " took", secs, "seconds"

我們可以創(chuàng)建一個decorator使它用起來更方便。

import time
from functools import wraps
...
def simple_profiling(fn):
    @wraps(fn)  # 對外暴露調(diào)用裝飾器函數(shù)的函數(shù)名和docstring
    def wrapped(*args, **kwargs):
        t1 = time.time()
        result = fn(*args, **kwargs)
        t2 = time.time()
        print (
            "@simple_profiling:" + fn.func_name + " took " + str(t2 - t1) + " seconds")
        return result
    return wrapped
...
@simple_profiling
def foo(a, b, c)
    ...

這個方法的優(yōu)點是簡單，額外開效非常低（大部分情況下可以忽略不計）。但缺點也很明顯，除了總用時，沒有任何其他信息。

Python的timeit模塊也提供了測量小段代碼執(zhí)行時間的方法。需要注意在使用timeit模塊時，GC會被臨時關閉，所以這個可能導致測試結(jié)果跟真實運行結(jié)果有差距。

python -m timeit [-n N] [-r N] [-s S] [-t] [-c] [-h] [statement ...]
-n : 執(zhí)行指定語句的次數(shù)
-r : 重復測量的次數(shù)（默認3次）
-s : 指定初始化代碼或構(gòu)建環(huán)境的導入語句
-t : 使用time.time() (Windows平臺以外的默認值)
-c : 使用time.clock() (Windows平臺默認值)

舉一個-s的例子，假設我們在test.py里面定義了一個函數(shù)foo

python -m timeit -n 5 -r 5 -s "import test" "test.foo(a,b,c)"
5 loops, best of 5: 28.6 usec per loop

timtie還可以在IPython環(huán)境下使用：

In [6]: timeit '"-".join(map(str, xrange(100)))'
100000000 loops, best of 3: 9.75 ns per loop

另外unix系統(tǒng)也提供time工具，用來統(tǒng)計腳本執(zhí)行的時間，它的特點是把運行時間分成real,user,sys三部分。

$ time python test_time.py

real    0m0.069s
user    0m0.038s
sys     0m0.033s

cProfile

cProfile是Python標準庫中的一個模塊，它可以非常仔細地分析代碼執(zhí)行過程中所有函數(shù)調(diào)用的用時和次數(shù)。cProfile最簡單的用法是用cProfile.run來執(zhí)行一段代碼，或是用python -m cProfile myscript.py來執(zhí)行一個腳本。例如

$ python -m cProfile -s cumulative -o profile.stats test_time.py
         5 function calls in 0.232 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.232    0.232 test_time.py:3(<module>)
        1    0.018    0.018    0.231    0.231 test_time.py:3(foo)
        1    0.177    0.177    0.177    0.177 {map}
        1    0.036    0.036    0.036    0.036 {method 'join' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

整個輸出結(jié)果給出了每一個函數(shù)的耗時信息。每個列的字段含義如下：

• ncalls: 函數(shù)被調(diào)用次數(shù)
• tottime: 函數(shù)總耗時，子函數(shù)的執(zhí)行時間不計算在內(nèi)
• percall: tottime / ncalls
• cumtime: 函數(shù)加上其所有子函數(shù)的總耗時
• percall: cumtime / ncalls

這個例子比較簡單，所有輸出很少，真實的例子估計輸出會非常多，我們可以把結(jié)果通過 -o profile.stats 把結(jié)果保存到文件，然后通過強大的pstats模塊來進行分析。關于pstats的具體使用可以看官方文檔。
關于使用cProfile進行性能分析時，推薦profilehooks，使用方法如下：

from profilehooks import profile

class SampleClass(ParentClass):
    @profile(filename="/tmp/SampleClass_do_something.stats", immediate=True, stdout=False)
    def do_something(self):
        ...

這里把輸出結(jié)果不輸出到stdout而是直接保存到/tmp/SampleClass_do_something.stats，因為是對長期運行的代碼進行profiling，所以這里把immediate設置成True，表示代碼執(zhí)行完立即輸出，而不是等程序結(jié)束。profile還有很多其他參數(shù)，詳細請看github上源碼注釋profilehooks.py

如果覺得pstats使用不方便，還可以使用一些圖形化工具，比如gprof2dot和RunSnakeRun來可視化分析cProfile的診斷結(jié)果。這兩個工具推薦一起使用，RunSnakeRun能很快發(fā)現(xiàn)那些函數(shù)執(zhí)行時間占比比較大，然后通過gprof2dot畫的函數(shù)調(diào)用圖來具體分析。

Line Profiler

我們通過cProfile定位到了具體的耗時函數(shù)，下面就需要具體定位瓶頸出在哪行代碼，這個時候就到了Line Profiler出場的時候了。與cProfile相比，Line Profiler的結(jié)果更加直觀，它可以告訴你一個函數(shù)中每一行的耗時。Line Profiler并不在標準庫中，需要用pip來安裝。

pip install line_profiler

line_profiler的使用特別簡單，在需要監(jiān)控的函數(shù)前面加上@profile裝飾器。然后用它提供的 kernprof -l -v source_code.py 進行診斷。