1. 程式人生 > >python效能分析之cProfile模組

python效能分析之cProfile模組

cProfile是標準庫內建的分析工具的其中一個,另外兩個是hotshot和profile

-s cumulative

-s cumulative開關告訴cProfile對每個函式累計花費的時間進行排序,他能讓我看到程式碼最慢的部分。
我們有這樣一個函式。
loopdemo.py

def foo():
    for a in range(0, 101):
        for b in range(0, 101):
            if a + b == 100:
                yield a, b
if __name__ == '__main__':
    for item in foo():
        print(item)

執行下面命令

python3 -m cProfile -s cumulative loopdemo.py

得到如下結果

         206 function calls in 0.001 seconds
         #在0.01秒內共發生了206次函式呼叫。包括cProfile的開銷。

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.001    0.001 {built-in method builtins.exec}
        1    0.000    0.000    0.001    0.001 loopdemo.py:7(<module>)
      102    0.001    0.000    0.001    0.000 loopdemo.py:7(foo)
      101    0.001    0.000    0.001    0.000 {built-in method builtins.print}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

其中對引數的解釋:
ncalls:表示函式呼叫的次數;
tottime:表示指定函式的總的執行時間,除掉函式中呼叫子函式的執行時間;
percall:(第一個percall)等於 tottime/ncalls;
cumtime:表示該函式及其所有子函式的呼叫執行的時間,即函式開始呼叫到返回的時間;
percall:(第二個percall)即函式執行一次的平均時間,等於 cumtime/ncalls;
filename:lineno(function):每個函式呼叫的具體資訊;
需要注意的是cProfile很難搞清楚函式內的每一行發生了什麼,是針對整個函式來說的。

-o profile.stats

我們可與你通過這個函式將結果輸出到一個檔案中,當然檔案的字尾名是任意的,這裡為了方便後面配合python中使用所以將字尾定為stats。
首先讓我們執行下面的命令

python3 -m cProfile -o loopdemo_profile.stats loopdemo.py

然後執行下面的指令碼

import pstats
p=pstats.Stats("loopdemo_profile.stats")
p.sort_stats("cumulative")
p.print_stats()
p.print_callers()  # 可以顯示函式被哪些函式呼叫
p.print_callees()  # 可以顯示哪個函式呼叫了哪些函式

可以看到輸出了和之前控制檯一樣的結果


         2006 function calls in 0.005 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.005    0.005 {built-in method builtins.exec}
        1    0.000    0.000    0.005    0.005 loopdemo.py:7(<module>)
     1001    0.004    0.000    0.004    0.000 {built-in method builtins.print}
     1002    0.000    0.000    0.000    0.000 loopdemo.py:30(foo2)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

   Ordered by: cumulative time

Function                                          was called by...
                                                      ncalls  tottime  cumtime
{built-in method builtins.exec}                   <- 
loopdemo.py:7(<module>)                           <-       1    0.000    0.005  {built-in method builtins.exec}
{built-in method builtins.print}                  <-    1001    0.004    0.004  loopdemo.py:7(<module>)
loopdemo.py:30(foo2)                              <-    1002    0.000    0.000  loopdemo.py:7(<module>)
{method 'disable' of '_lsprof.Profiler' objects}  <- 


   Ordered by: cumulative time

Function                                          called...
                                                      ncalls  tottime  cumtime
{built-in method builtins.exec}                   ->       1    0.000    0.005  loopdemo.py:7(<module>)
loopdemo.py:7(<module>)                           ->    1002    0.000    0.000  loopdemo.py:30(foo2)
                                                        1001    0.004    0.004  {built-in method builtins.print}
{built-in method builtins.print}                  -> 
loopdemo.py:30(foo2)                              -> 
{method 'disable' of '_lsprof.Profiler' objects}  -> 

line_profiler

安裝

pip3 install Cpython
pip3 install Cython git+https://github.com/rkern/line_profiler.git