《Python高性能程式設計》——2.4 計時的簡單方法——列印和修飾

本節書摘來自異步社群《python高性能程式設計》一書中的第2章，第2.4節，作者[美] 戈雷利克 （micha gorelick），胡世傑，徐旭彬 譯，更多章節内容可以通路雲栖社群“異步社群”公衆号檢視。

運作例2-4，我們看到的輸出是由代碼中幾句print語句生成的。在ian的筆記本上用cpython 2.7跑這段代碼要花大約12秒。運作時間一般都會有一些波動。你必須在計時的同時觀察這些正常的變化，否則你可能會誤把某個随機的運作時間的變化當作是由于某次代碼的改進造成的。

你的計算機在運作你的代碼時還會進行其他任務，比如通路網絡、磁盤或ram，這些因素都會導緻程式運作時間的變化。

ian的筆記本是一台dell e6420，擁有一個intel core i7-2720qm的cpu（2.20ghz，6mb緩存，4核）以及8gb的ram，作業系統是ubuntu 13.10。

在calc_pure_python中（例2-2），我們能看到一些print語句。這是最簡單的在函數内部測量一段代碼執行時間的方法。這個基本方法既快且髒，是在你剛開始着手調查代碼時非常有用的手段。

在代碼除錯和性能分析上使用print語句是常用的手段。雖然它很快就會變得無法管理，但适用于簡短的調查。用完它們以後要記得收拾幹淨，否則它們會搞亂你的stdout。

一個稍微幹淨一點的方法是使用修飾器——在需要調查的函數上面增加一行代碼。我們的修飾器十分簡單，僅僅複制了print語句的功能。後面我們會讓它變得更加進階。

在例2-5中，我們定義了一個新函數timefn，它以一個函數fn為參數。它的内嵌函數measure_time接受args（數量可變的位置參數）以及*kwargs（數量可變的鍵值對參數）等參數并将其傳入fn執行。在執行fn前後，我們抓取time.time()并将結果和fn.func_name一起列印出來。使用這個修飾器的開銷很小，但如果你調用上千萬次fn，開銷就會變得引人注意。我們用@wraps(fn)将函數名和docstring暴露給fn的調用者（否則調用者看到的将是修飾器自身的函數名和docstring，而不是被修飾的函數的）。

例2-5　定義一個修飾器來自動測量時間

當我們運作這個版本的代碼時（之前的print語句依然保留），我們會看到修飾器列印的執行時間要略快于calc_pure_python列印的時間。這是由于函數的調用帶來了額外開銷（差異非常小）：

我們可以用timeit子產品作為另一種測量執行速度的方法。通常來說，你會在解決問題的過程中用它來為各種簡單的語句計時。

你可以從指令行運作timeit如下：

注意你必須以-s指令在設定階段導入julia1子產品，因為calc_pure_python來自那個子產品。timeit有一些合理的預設值适用于一段簡短的代碼，但對于要長期運作的代碼來說，最好指定循環次數（-n 5）以及重複次數（-r 5）。timeit會對語句循環執行n次并計算平均值作為一個結果，重複r次并選出最好的那個結果。

如果我們不指定-n和-r運作timeit，預設是循環10次重複5次，需要6分鐘。改變預設值可以讓你更快獲得結果。

我們隻關注最好的那個結果，平均值以及最差結果可能是由于其他程序的影響。選擇循環5次重複5次應該能給我們一個較為公正的結果：

試着多運作幾次，看看我們會不會得到不同的結果——你可能需要更多的重複次數來獲得一個穩定的最佳結果時間。在這一點上不存在“正确”的配置，是以如果你發現你的計時結果變動範圍很廣，你就要選擇更高的重複次數，直到獲得穩定的最終結果。

我們的結果顯示調用calc_pure_python的總體開銷是13.1秒（最佳情況），而@timefn修飾器測算的單次調用calculate_z_serial_purepython耗時12.2秒。中間的差别主要是用于建立zs和cs清單的時間。

在ipython内部，我們可以用同樣的方式使用%timeit魔法函數。如果你在ipython中用互動的方式開發你的代碼且函數在本地名字空間（可能是因為你正在使用%run），那麼你可以用：

還有一點值得考慮的是一台計算機上的負載變化。很多背景運作的任務（如dropbox、備份等）都會随機影響cpu和磁盤資源。網頁上的腳本也會導緻不可預測的資源使用。圖2-4顯示了我們剛剛進行的計時過程中某個cpu的使用率達到了100%，機器中的其他核心都在輕松處理其他的任務。

系統螢幕會時不時地顯示這台機器上的活動峰值。有必要檢查會不會有其他事件發生影響了你的關鍵資源（cpu、磁盤、網絡）。