附錄B 更多IPython系統(tǒng)相關(guān)內(nèi)容

B.3.2 對代碼測時：%time和%timeit

對于更大規(guī)睦或更長時間運行的數(shù)據(jù)分析應(yīng)用程序攒砖，你可能希望測量各個組件或單個語句或函數(shù)調(diào)用的執(zhí)行時間叮称。你可能需要一個在復(fù)雜過程中哪些函數(shù)最耗時的報告。幸運的是坞淮，IPython允許你非常方便地在開發(fā)嘀略、測試代碼的時候獲得這些信息。

手工使用內(nèi)置time模塊及其函數(shù)time.clock和time.time通常是單調(diào)和重復(fù)的踩窖，因為你必須編寫相同的無趣樣板代碼

由于這是一個很常見的操作坡氯，而IPython有兩個魔術(shù)函數(shù)，%time和%timeit洋腮，為你自動執(zhí)行此過程箫柳。

%time一次運行一條語句，并報告總執(zhí)行時間徐矩。假設(shè)我們有一大串字符串滞时，我們想比較不同的選擇所有的字符串中以特殊前綴開始的字符串的方法。這里有一個包含600,000個字符串的列表和兩個只選出以’foo’開頭的方法（見圖B-1）

image

Wall time（"wall-clock time"簡寫滤灯，壁鐘時間）是我們主要感興趣的數(shù)字坪稽。所以，看起來第一種方法需要兩倍以上的時間鳞骤，但這不是一個非常精確的測量窒百。如果你嘗試多用%time測試，你就發(fā)現(xiàn)測試結(jié)果是個變量豫尽。為了獲得更精確的測量篙梢，可以使用%timeit魔術(shù)函數(shù)。給定任意的語句美旧，%timeit有多次運行語句以產(chǎn)生更準(zhǔn)確的平均運行時間的功能（見圖B-2）

image

這個看似普通的例子表明渤滞，理解本書中使用的Python標(biāo)準(zhǔn)庫、NumPy榴嗅、pandas以及其他的類庫的性能特征是很有必要的妄呕。在更大型的數(shù)據(jù)分析應(yīng)用中，相差的毫秒就開始累加了嗽测！

%timeit對于執(zhí)行時間很短的分析語句和函數(shù)特別有用酝润，甚至在微秒（百萬分之一秒）或納秒（十億分之一秒）的級別依然有效驻呐。

這些時間可能看起來微不足道习柠，但是蛉艾，調(diào)用100萬次的20微秒函數(shù)比5毫秒的函數(shù)要多用15秒。在之前的例子中晤愧，我們可以非常直接地對比兩個字符串操作來理解它們的性能差異（見圖B-3）

image

B.3.3 基礎(chǔ)分析：%prun和%run -p

代碼分析與代碼測試相關(guān)性很高大莫，但代碼分析更多關(guān)注于時間開銷的位置。主要的Python分析工具是cProfile模塊养涮，該模塊不是專用于IPython葵硕。cProfile執(zhí)行程序或任意代碼塊眉抬，同時記錄每個函數(shù)花費多少時間贯吓。

使用cProfile的常用方法是在命令行上運行整個程序懈凹，并輸出每個函數(shù)的聚合時間。假設(shè)我們有一個簡單的腳本悄谐，它在循環(huán)中執(zhí)行一些線性代數(shù)（計算一系列100×100矩陣的最大絕對特征值）：

import numpy as np
from numpy.linalg import eigvals
def run_experiment(niter=100):
    K = 100
    results = []
    for _ in xrange(niter):
        mat = np.random.randn(K, K)
        max_eigenvalue = np.abs(eigvals(mat)).max()
        results.append(max_eigenvalue)
    return results
some_results = run_experiment()
print 'Largest one we saw: %s' % np.max(some_results)

你可以使用下面的代碼在命令行中通過cProfile運行腳本：

python -m cProfile cprof_example.py

如果你按照上面的代碼嘗試介评，你會發(fā)現(xiàn)輸出是按照函數(shù)名排序的。這讓我們很難了解大部分時間花在哪里爬舰，所以通常需要使用-s標(biāo)志指定一個排序順序：

$ python -m cProfile -s cumulative cprof_example.py
Largest one we saw: 11.923204422
    15116 function calls (14927 primitive calls) in 0.720 seconds
Ordered by: cumulative time
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.001    0.001    0.721    0.721 cprof_example.py:1(<module>)
  100    0.003    0.000    0.586    0.006 linalg.py:702(eigvals)
  200    0.572    0.003    0.572    0.003 {numpy.linalg.lapack_lite.dgeev}
    1    0.002    0.002    0.075    0.075 __init__.py:106(<module>)
  100    0.059    0.001    0.059    0.001 {method 'randn')
    1    0.000    0.000    0.044    0.044 add_newdocs.py:9(<module>)
    2    0.001    0.001    0.037    0.019 __init__.py:1(<module>)
    2    0.003    0.002    0.030    0.015 __init__.py:2(<module>)
    1    0.000    0.000    0.030    0.030 type_check.py:3(<module>)
    1    0.001    0.001    0.021    0.021 __init__.py:15(<module>)
    1    0.013    0.013    0.013    0.013 numeric.py:1(<module>)
    1    0.000    0.000    0.009    0.009 __init__.py:6(<module>)
    1    0.001    0.001    0.008    0.008 __init__.py:45(<module>)
  262    0.005    0.000    0.007    0.000 function_base.py:3178(add_newdoc)
100 0.003 0.000 0.005 0.000 linalg.py:162(_assertFinite)
...

輸出只顯示最前面的15行们陆。通過掃描cumtime列來查看每個函數(shù)內(nèi)花費的總時間是最容易的。

請注意情屹，如果一函數(shù)調(diào)用了其他一些函數(shù)坪仇，時鐘并不會停止運行。cProfile記錄了每個函數(shù)調(diào)用的起始和結(jié)束時間垃你，并以此來生成耗時椅文。
除了命令行的使用，還可以通過編程方式使用cProfile來分析任意代碼塊惜颇，而無須運行新進程皆刺。IPython使用%prun命令和%run的-p選項為此功能提供了方便的接口。%prun與cProfile采用相同的“命令行選項”凌摄，但會分析任意Python語句而不是整個．py文件：

In [4]: %prun -l 7 -s cumulative run_experiment()
          4203 function calls in 0.643 seconds
Ordered by: cumulative time
List reduced from 32 to 7 due to restriction <7>
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.000    0.000    0.643    0.643 <string>:1(<module>)
    1    0.001    0.001    0.643    0.643 cprof_example.py:4(run_experiment)
    100    0.003    0.000    0.583    0.006 linalg.py:702(eigvals)
    200    0.569    0.003    0.569    0.003 {numpy.linalg.lapack_lite.dgeev}
    100    0.058    0.001    0.058    0.001 {method 'randn'}
    100    0.003    0.000    0.005    0.000 linalg.py:162(_assertFinite)
    200    0.002    0.000    0.002    0.000 {method 'all' of 'numpy.ndarray'}

同樣羡蛾，調(diào)用%run -p -s cumulative cprof_example.py與命令行方法具有相同的效果，并且你不必離開IPython锨亏。

在Jupyter notebook中痴怨，你可以使用%%prun魔術(shù)方法（兩個百分號%）來分析整個代碼塊。這會彈出一個包含配置文件輸出的獨立窗口器予。獨立窗口對于快速回答如下問題很有用：“為什么代碼塊需要很長時間才能運行浪藻？”

還有其他工具可以幫助你在使用IPython或Jupyter時更容易理解配置文件。其中一個是SnakeViz（https://github.com/jiffyclub/snakeviz）劣摇，它使用d3.js生成配置文件結(jié)果的交互式可視化珠移。

B.3.4 逐行分析函數(shù)

某些情況下，你從%prun（或者及其他基于cProfile的分析方法）獲得的信息可能無法完整闡述函數(shù)的執(zhí)行時間末融，或者特別復(fù)雜而使得根據(jù)函數(shù)名聚合得到的結(jié)果太難而無法解釋钧惧。對于這種情況，有一個小的庫勾习，叫作line_profiler（從PyPI或者其他的包管理工具中獲得）浓瞪。
這個庫包含了一個IPython拓展，增加了一個新的魔術(shù)函數(shù)%lprun, %lprun可以對一或多個函數(shù)進行逐行分析巧婶。你可以通過修改你的IPython配置類開啟這個拓展（參考IPython官方文檔或本章之后介紹配置的小節(jié)）乾颁，修改配置時增加下面一行：

# IPython拓展需要載入的模塊名稱列表
c.TerminalIPythonApp.extensions = ['line_profiler']

你也可以運行以下命令：

%load_ext line_profiler

line_profiler可以按編程的方式使用（參考line_profiler完整文檔）涂乌，但是可能最有效的使用方式還是在IPython中交互式使用。假設(shè)你有一個prod_mod模塊英岭，該模塊含有以下進行NumPy數(shù)組操作的代碼：

from numpy.random import randn
def add_and_sum(x, y):
    added = x + y
    summed = added.sum(axis=1)
    return summed
def call_function():
    x = randn(1000, 1000)
    y = randn(1000, 1000)
    return add_and_sum(x, y)

如果我們想要知道add_and_sum函數(shù)的性能湾盒，%prun會給出以下結(jié)果：

In [569]: %run prof_mod
In [570]: x = randn(3000, 3000)
In [571]: y = randn(3000, 3000)
In [572]: %prun add_and_sum(x, y)
          4 function calls in 0.049 seconds
    Ordered by: internal time
    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.036    0.036    0.046    0.046 prof_mod.py:3(add_and_sum)
        1    0.009    0.009    0.009    0.009 {method 'sum' of 'numpy.ndarray'}
        1    0.003    0.003    0.049    0.049 <string>:1(<module>)

這不是特別讓人理解。通過激活line_profiler的IPython擴展诅妹，可以使用新的命令% lprun罚勾。使用的唯一區(qū)別是我們必須向%lprun指明我們希望分析哪些函數(shù)。一般的語法是：

%lprun -f func1 -f func2 statement to profile

在這種情況下吭狡，我們想要對add_and_sum做分析尖殃，因此我們運行以下代碼：

In [573]: %lprun -f add_and_sum add_and_sum(x, y)
Timer unit: 1e-06 s
File: prof_mod.py
Function: add_and_sum at line 3
Total time: 0.045936 s
Line #      Hits      Time  Per Hit   % Time Line Contents
==========================================================
    3                                          def add_and_sum(x, y):
    4          1     36510  36510.0     79.5      added = x + y
    5          1      9425   9425.0     20.5     summed = added.sum(axis=1)
    6          1          1      1.0      0.0     return summed

這結(jié)果更容易解釋。在這種情況下划煮，我們分析了我們在之前語句中使用的相同函數(shù)送丰。查看之前的模塊代碼，我們可以調(diào)用并分析call_function以及add_and_sum弛秋，從而全面了解代碼的性能：

In [574]: %lprun -f add_and_sum -f call_function call_function()
Timer unit: 1e-06 s
File: prof_mod.py
Function: add_and_sum at line 3
Total time: 0.005526 s
Line #       Hits           Time  Per Hit    % Time  Line Contents
==============================================================
    3                                           def add_and_sum(x, y):
    4         1         4375   4375.0     79.2      added = x + y
    5         1         1149   1149.0     20.8      summed = added.sum(axis=1)
    6         1            2      2.0      0.0      return summed
File: prof_mod.py
Function: call_function at line 8
Total time: 0.121016 s
Line #       Hits           Time  Per Hit    % Time  Line Contents
==============================================================
    8                                           def call_function():
    9          1        57169  57169.0        47.2   x = randn(1000, 1000)
     10          1         58304  58304.0     48.2      y = randn(1000, 1000)
     11          1          5543    5543.0      4.6      return add_and_sum(x, y)

作為一個通用的經(jīng)驗規(guī)則器躏，我傾向于使用%prun（基于cProfile）作為”宏觀“的性能分析，用%lprun（基于line_profiler）作為微觀分析铐懊。對于這兩個工具的理解都是非常有意義的邀桑。

注：你必須明確指定要使用% lprun進行分析的函數(shù)的名稱，原因是“回溯”每行的執(zhí)行時間的開銷很大科乎”诨回溯不感興趣的函數(shù)可能會顯著改變分析結(jié)果。