Python 3 Tutorial 第十二堂（1）效能評測


效能評測是我們要談的最後一個主題了，這是個很大的議題，嗯 … 應該說，這個課程中每一個主題，都可以是個很大的議題，雖然課程接近尾聲了，但別忘了，這只是個簡短的生態之旅！

拉回來效能評測這個主題，就 Python 內建模組來說，我們要介紹的有：

  • timeit 用來量測一個小程式片段的執行時間。
  • cProfile 用來收集程式執行時的一些時間數據，提供各種統計數據，對大多數的使用者來說是不錯的工具，這是用 C 撰寫的擴充模組。
  • profile 介面上彷造了 cProfile，不過是用純 Python 來實現的模組，因此有較高的互通性；cProfile 在評測時有較低的額外成本，不過並不是所有系統上都有提供。

先來看看 timeit 的介紹 …

timeit 模組

在介紹 timeit 之前，來看一個情境，你會怎麼撰寫程式來產生以下執行結果呢？

all = ''
for s in strs: # strs 是 ['0', '1', '2', '3', ..., '98']
    all = all + s + ',' 
all = all + '99'

也許你聽過一種說法，對 list 使用 join 會比較快？

','.join(strs) # strs 是 ['0', '1', '2', '3', ..., '99']

傳說拔到獅子的鬃毛，程式就會自己生出來嘞！別再相信沒有根據的說法了，試試 timeit！

來看看喔！如果有個 s 字串是這樣定義的：

prog = '''
all = ''
for s in strs:
    all = all + s + ','
all = all + '99'
'''

那麼，以下的 timeit 測試，似乎證明了 + 串接字串一定比較慢，而使用 join 一定比較快：

>>> prog = '''
... all = ''
... for s in strs:
...     all = all + s + ','
... all = all + '99'
... '''
>>> timeit.timeit(prog, 'strs = [str(n) for n in range(99)]')
14.954506739999943
>>> timeit.timeit('",".join(strs)', 'strs = [str(n) for n in r
1.7757719399996859
>>>

timeit 的第一個參數接受一個用字串表示的程式片段，第二個參數是準備測試用的材料，也是用字串表示的程式片段，timeit 在材料準備好之後，就會運行第一個參數指定的程式片段並量測時間，單位是秒！嗯！就結果看來，join 勝出！

不過，以下卻是相反的結果：

>>> timeit.timeit(prog, 'strs = (str(n) for n in range(99))')
0.08317589699981909
>>> timeit.timeit('",".join(strs)', 'strs = (str(n) for n in range(99))')
0.28092733899984523
>>>

差別在哪呢？在準備 strs 時，兩個都將 [] 改成了 () 罷了！這邊的重點並不在探討哪個快慢，只是想表示兩個觀念：

  • 效能是程式結合後的整體考量，不是單一概念
  • 效能不是用猜的，要有實際的評測作為依據

timeit 預設是執行程式片段 1,000,000 次，然後取平均時間，以下是幾個直接透過 API 運行的範例：

>>> timeit.timeit('strs=[str(n) for n in range(99)]\n', number = 10000)
0.23513332900029127
>>> timeit.timeit('strs=(str(n) for n in range(99))\n', number = 10000)
0.007505773000048066
>>> timeit.timeit('",".join([str(n) for n in range(99)])', number = 10000)
0.26162150800018935
>>> timeit.timeit('",".join((str(n) for n in range(99)))', number = 10000)
0.2882215190002171
>>> timeit.timeit('",".join(map(str, range(100)))', number = 10000)
0.20434793499998705
>>>

也可以透過命令列的指令來執行評測：

$ python3.5 -m timeit '",".join(str(n) for n in range(100))'
10000 loops, best of 3: 27.6 usec per loop

一個更實際的例子，可以在 Lab 檔案的 demos/timeit 中找到，這是一個評測排序的範例：

import timeit
repeats = 1000
for f in ('selectionSort', 'insertionSort', 'bubbleSort'):
    t = timeit.Timer('{0}([10, 9, 1, 2, 5, 3, 8, 7])'.format(f),
        'from sorting import selectionSort, insertionSort, bubbleSort')
    sec = t.timeit(repeats) / repeats
    print('{f}\t{sec:.6f} sec'.format(**locals()))

以下是執行的結果：

$ python3.5 timeit_sorting.py
selectionSort   0.000021 sec
insertionSort   0.000017 sec
bubbleSort  0.000058 sec

cProfile（profile）

cProfile 提供有關程式運行時更多的統計資訊，你要有一個主要的進入點。例如：

import cProfile
import sorting
import random

l = list(range(500))
random.shuffle(l)
cProfile.run('sorting.selectionSort(l)')

以下是個執行後的統計資訊：

$ python3.5 profile_sorting.py
         251503 function calls (251004 primitive calls) in 0.105 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.105    0.105 <string>:1(<module>)
   124750    0.040    0.000    0.066    0.000 sorting.py:11(<lambda>)
      500    0.008    0.000    0.008    0.000 sorting.py:12(<listcomp>)
      499    0.005    0.000    0.005    0.000 sorting.py:14(<listcomp>)
   124750    0.026    0.000    0.026    0.000 sorting.py:3(ascending)
        1    0.000    0.000    0.105    0.105 sorting.py:6(selectionSort)
    500/1    0.003    0.000    0.105    0.105 sorting.py:9(__select)
      500    0.024    0.000    0.089    0.000 {built-in method _functools.reduce}
        1    0.000    0.000    0.105    0.105 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

當中有許多欄位需要解釋一下：

  • ncalls - “number of calls” 的縮寫，也就是對特定函式的呼叫次數。
  • tottime - “total time” 的縮寫，花費在函式上的執行時間（不包括子函數呼叫的時間）。
  • percall - tottime / ncalls 的結果。
  • cumtime - “cumulative time” 的縮寫，花費在函式與所有子函式的時間（從呼叫至離開）。
  • percall - cumtime / ncalls 的結果。
  • filename:lineno(function) - 提供程式碼執行時的位置資訊。

使用 pstats

你可以使用 pstats 對 cProfile 的結果，進行各種運算與排序，可以先將 cProfile 收集的結果，儲存為一個檔案：

cProfile.run('sorting.selectionSort(l)', 'select_stats')

然後，可以如下使用 pstats 載入檔案，並進行排序等運算：

import pstats
p = pstats.Stats('select_stats')
p.strip_dirs().sort_stats('name').print_stats()
p.sort_stats('cumulative').print_stats(10)
p.sort_stats('time').print_stats(10)

一個執行結果如下：

$ python3.5 pstats_demo.py
Fri Mar 11 10:54:32 2016    select_stats

         251503 function calls (251004 primitive calls) in 0.098 seconds

   Ordered by: function name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      500    0.023    0.000    0.081    0.000 {built-in method _functools.reduce}
        1    0.000    0.000    0.098    0.098 {built-in method builtins.exec}
   124750    0.039    0.000    0.058    0.000 sorting.py:11(<lambda>)
      500    0.008    0.000    0.008    0.000 sorting.py:12(<listcomp>)
      499    0.005    0.000    0.005    0.000 sorting.py:14(<listcomp>)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.097    0.097 <string>:1(<module>)
    500/1    0.003    0.000    0.097    0.097 sorting.py:9(__select)
   124750    0.019    0.000    0.019    0.000 sorting.py:3(ascending)
        1    0.000    0.000    0.097    0.097 sorting.py:6(selectionSort)


Fri Mar 11 10:54:32 2016    select_stats

         251503 function calls (251004 primitive calls) in 0.098 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.098    0.098 {built-in method builtins.exec}
        1    0.000    0.000    0.097    0.097 <string>:1(<module>)
        1    0.000    0.000    0.097    0.097 sorting.py:6(selectionSort)
    500/1    0.003    0.000    0.097    0.097 sorting.py:9(__select)
      500    0.023    0.000    0.081    0.000 {built-in method _functools.reduce}
   124750    0.039    0.000    0.058    0.000 sorting.py:11(<lambda>)
   124750    0.019    0.000    0.019    0.000 sorting.py:3(ascending)
      500    0.008    0.000    0.008    0.000 sorting.py:12(<listcomp>)
      499    0.005    0.000    0.005    0.000 sorting.py:14(<listcomp>)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


Fri Mar 11 10:54:32 2016    select_stats

         251503 function calls (251004 primitive calls) in 0.098 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   124750    0.039    0.000    0.058    0.000 sorting.py:11(<lambda>)
      500    0.023    0.000    0.081    0.000 {built-in method _functools.reduce}
   124750    0.019    0.000    0.019    0.000 sorting.py:3(ascending)
      500    0.008    0.000    0.008    0.000 sorting.py:12(<listcomp>)
      499    0.005    0.000    0.005    0.000 sorting.py:14(<listcomp>)
    500/1    0.003    0.000    0.097    0.097 sorting.py:9(__select)
        1    0.000    0.000    0.098    0.098 {built-in method builtins.exec}
        1    0.000    0.000    0.097    0.097 sorting.py:6(selectionSort)
        1    0.000    0.000    0.097    0.097 <string>:1(<module>)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

你可以直接使用 cProfile 模組將另一個模組載入執行，例如：

python3.5 -m cProfile myscript.py

或者是：

cProfile.py [-o output_file] [-s sort_order]