[ Python 文章收集 ] Python 用 cProfile 測量程式效能瓶頸與 gprof2dot 視覺化分析教學

Source From Here 
Preface 
這裡介紹如何使用 cProfile 測量 Python 程式效能、找出效能瓶頸，並以 gprof2dot 產生視覺化分析圖表。較為大型的計算程式在開發完成後，通常都會接續著進行程式的執行效能測量與分析（profiling），找出程式的瓶頸所在，針對少數關鍵的程式碼進一步做最佳化，改善整體程式的執行速度。 

Python 範例程式 
以下是一個簡單的 Python 程式 pi.py，此程式的目的是以 蒙地卡羅 方法計算 Pi 的近似值： 
- pi.py 

view plaincopy to clipboardprint?

1. from __future__ import division  
2. import random  
3.   
4. # Number of simulation   
5. NB_POINTS = 10**7  
6.   
7. # Check if the point is within the circle  
8. def in_circle(x, y):  
9.   return x**2 + y**2 < 1  
10.   
11. # Calculate Pi approximation  
12. def compute_pi(nb_it):  
13.   inside_count = sum(1 for _ in range(nb_it) if in_circle(random.random(), random.random()))  
14.   return (inside_count / nb_it) * 4  
15.   
16. if __name__ == "__main__":  
17.   print(compute_pi(NB_POINTS))  

執行結果: 

view plaincopy to clipboardprint?

1. In [1]: import pi  
2. In [3]: %time pi.compute_pi(1000)  
3. Wall time: 1.56 ms  
4. Out[3]: 3.12  
5.   
6. In [4]: %time pi.compute_pi(100000)  
7. Wall time: 124 ms  
8. Out[4]: 3.13956  
9.   
10. In [5]: %timeit pi.compute_pi(100000)  
11. 61.5 ms ± 2.12 ms per loop (mean ± std. dev. of 7 runs, 10 loops each)  

接下來我們將示範如何以 cProfile 來測量這個程式的執行狀況. 

cProfile 分析程式執行狀況 
若要測量一個獨立的程式，最直接又簡單的方式就是在執行時引入 cProfile 模組： 

# python -m cProfile -s cumtime pi.py

在使用 -m 引入 cProfile 模組 之後，再加上 -s 參數指定排序欄位，這裡我們以累計執行時間來排序（cumtime），執行後就會輸出類似這樣的量測報表： 

view plaincopy to clipboardprint?

1. 3.1417176  
2.          37855992 function calls (37855948 primitive calls) in 10.176 seconds  
3.   
4.    Ordered by: cumulative time  
5.   
6.    ncalls  tottime  percall  cumtime  percall filename:lineno(function)  
7.       5/1    0.000    0.000   10.176   10.176 {built-in method builtins.exec}  
8.         1    0.000    0.000   10.176   10.176 pi.py:1()  
9.         1    0.000    0.000   10.169   10.169 pi.py:12(compute_pi)  
10.         1    0.605    0.605   10.169   10.169 {built-in method builtins.sum}  
11.   7854295    4.221    0.000    9.564    0.000 pi.py:13()  
12. 10000000    4.182    0.000    4.182    0.000 pi.py:8(in_circle)  
13. 20000000    1.161    0.000    1.161    0.000 {method 'random' of '_random.Random' objects}  
14.      10/2    0.000    0.000    0.007    0.003 :966(_find_and_load)  
15.      10/2    0.000    0.000    0.006    0.003 :936(_find_and_load_unlocked)  
16.      10/2    0.000    0.000    0.006    0.003 :651(_load_unlocked)  
17.       4/2    0.000    0.000    0.005    0.003 :672(exec_module)  
18.      16/2    0.000    0.000    0.005    0.002 :211(_call_with_frames_removed)  
19.         1    0.000    0.000    0.005    0.005 random.py:38()  
20.         1    0.000    0.000    0.002    0.002 hashlib.py:54()  
21.        10    0.000    0.000    0.002    0.000 :870(_find_spec)  
22.        10    0.000    0.000    0.002    0.000 :564(module_from_spec)  
23.         5    0.000    0.000    0.002    0.000 :1149(find_spec)  
24.         5    0.000    0.000    0.002    0.000 :1117(_get_spec)  
25.        19    0.000    0.000    0.002    0.000 :1233(find_spec)  
26.         1    0.000    0.000    0.002    0.002 :919(create_module)  
27.         1    0.002    0.002    0.002    0.002 {built-in method _imp.create_dynamic}  
28.        28    0.000    0.000    0.002    0.000 :75(_path_stat)  
29.        28    0.001    0.000    0.001    0.000 {built-in method nt.stat}  
30.        ... 略 ...  

這個報表的欄位意義如下： 

測試程式碼片段 
如果只是要在 Python 程式中測試幾行程式的執行效能，可以使用 cProfile.run 執行要測量的程式碼： 

view plaincopy to clipboardprint?

1. from __future__ import division  
2. import random  
3.   
4. # Import cProfile module  
5. import cProfile  
6.   
7. # Number of simulation   
8. NB_POINTS = 10**7  
9.   
10. # Check if the point is within the circle  
11. def in_circle(x, y):  
12.   return x**2 + y**2 < 1  
13.   
14. # Calculate Pi approximation  
15. def compute_pi(nb_it):  
16.   inside_count = sum(1 for _ in range(nb_it) if in_circle(random.random(), random.random()))  
17.   return (inside_count / nb_it) * 4  
18.   
19. if __name__ == "__main__":  
20.   # Measuring performance of API:compute_pi  
21.   cProfile.run('compute_pi(NB_POINTS)')  

這樣就會輸出程式碼片段的測量結果： 

view plaincopy to clipboardprint?

1. # python pi.py  
2.          37854424 function calls in 11.937 seconds  
3.   
4.    Ordered by: standard name  
5.   
6.    ncalls  tottime  percall  cumtime  percall filename:lineno(function)  
7.         1    0.000    0.000   11.937   11.937 :1()  
8. 10000000    5.168    0.000    5.168    0.000 pi.py:11(in_circle)  
9.         1    0.000    0.000   11.937   11.937 pi.py:15(compute_pi)  
10.   7854419    4.904    0.000   11.289    0.000 pi.py:16()  
11.         1    0.000    0.000   11.937   11.937 {built-in method builtins.exec}  
12.         1    0.648    0.648   11.937   11.937 {built-in method builtins.sum}  
13.         1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}  
14. 20000000    1.216    0.000    1.216    0.000 {method 'random' of '_random.Random' objects}  

cProfile 結果輸出至檔案 
由於 cProfile 的報表非常長，若是較為複雜的程式，我們會把這些資料以輸出至檔案： 

# python3 -m cProfile -o pi.pstats pi.py

-o 參數可以指定輸出的檔案名稱，其輸出的檔案格式是二進位檔，若要觀看這個檔案，可以使用 Python 的 pstats 模組： 

# python -m pstats pi.pstats

進入 pstats 模組 的互動式環境後，可用各種指令來整理與查看報表，鍵入問號 ? 可以看到可用的指令。最常用的指令就使用 sort 設定排序欄位: 

pi.pstats% ?

Documented commands (type help ):
========================================
EOF add callees callers help quit read reverse sort stats strip

pi.pstats% sort cumtime
pi.pstats% stats

view plaincopy to clipboardprint?

1. Sat Jun 29 10:49:08 2019    pi.pstats  
2.   
3.          37854650 function calls (37854605 primitive calls) in 16.319 seconds  
4.   
5.    Ordered by: cumulative time  
6.   
7.    ncalls  tottime  percall  cumtime  percall filename:lineno(function)  
8.       6/1    0.000    0.000   16.319   16.319 {built-in method builtins.exec}  
9.         1    0.000    0.000   16.319   16.319 pi.py:1()  
10.         1    0.000    0.000   16.306   16.306 pi.py:15(compute_pi)  
11.         1    0.981    0.981   16.306   16.306 {built-in method builtins.sum}  
12.   7852679    6.700    0.000   15.325    0.000 pi.py:16()  
13. 10000000    6.820    0.000    6.820    0.000 pi.py:11(in_circle)  
14. 20000000    1.804    0.000    1.804    0.000 {method 'random' of '_random.Random' objects}  
15. ...  

以 gprof2dot 產生視覺化圖形 
若程式架構很複雜，光看簡單的文字報表可能會很難分析，這時候我們可以使用 gprof2dot 這個小工具，把 pstats 的資料轉為 dot 的格式，再將 dot 資料畫成圖形，以視覺化的方式呈現程式中各個函數之間的執行關係。 

首先安裝 gprof2dot 這個 Python 模組: 

# sudo pip3 install gprof2dot

若要畫圖的話，也要安裝 graphviz： 

// Ubuntu Linux
# sudo apt-get install graphviz
// CentOS Linux
# sudo yum install graphviz

安裝好必要的工具之後，就可以將剛剛產生的 pi.pstats 轉為 dot 資料，直接畫出圖形來： 

# python3 -m gprof2dot -f pstats pi.pstats | dot -T png -o pi_profile.png

畫出來的圖會像這樣： 

上面這個計算 Pi 的範例因為比較單純，所以程式的流程圖畫出來比較陽春，感覺不出他有多好用，但若是換成實際的範例就會差很多。 

Supplement 
* profile and pstats — Performance Analysis 
* Python 3 Tutorial 第十二堂（1）效能評測