问题定义
想要优化Java中的内存管理，就要查看GC_log来定位内存瓶颈；同理，想要优化python代码，就要统计各函数的运行时间来定位性能瓶颈。
最方便的就是直接使用jupyter notebook自带的两个magic指令：%prun和%lprun
注意：本文默认读者已经熟悉Jupyter notebook和python基础。如果您需要复习，可以参考这篇文章
%prun[1]
用来统计各函数调用次数及耗时。e.g. :
def f():
# additional line1...
# additional line2...
scores = detector.run_cases(cases_ballon, allow_near_phones=False, show_phone_heatmap=False, fig_ratio=(1, 1))
# additional line3...
# -T选项指定写到的文本文件， -l选项指定只显示前多少行
# 另外也可以用 -l <partial func name> 来过滤，只保留name包含指定子串的函数
%prun -T ./res/prun.txt -l 20 f()
# 另外还有一个cell magic，叫 %%prun
# 它相当于把cell内的多行代码，合并成一行长代码；作为最后一个参数送给 %prun；以免用f()来封装代码的麻烦
运行上述cell，会在jupyter notebook中弹窗显示如下结果，并写到文本文件./res/prun.txt
982179 function calls (971601 primitive calls) in 2.241 seconds
Ordered by: internal time
List reduced from 1716 to 5 due to restriction <5>
ncalls tottime percall cumtime percall filename:lineno(function)
1390 1.422 0.001 1.551 0.001 ctc_based_kws.py:320(score_by_sliding_window)
436939 0.126 0.000 0.126 0.000 {built-in method builtins.max}
81438 0.020 0.000 0.033 0.000 {built-in method builtins.isinstance}
7639/7480 0.015 0.000 0.017 0.000 {built-in method numpy.core.multiarray.array}
2797 0.014 0.000 0.019 0.000 weakref.py:101(__init__)
如上所示，累计耗时最多的function call为score_by_sliding_window()，位于ctc_based_kws.py:320，消耗了1.422秒；其次是某处对python/numpy内置的max()的调用。
通过prun能获得的信息就是这些，只能精确到函数级，而且对于内置函数提供的有用信息并不多。
想要进一步定位问题，可以对关键的几个函数实施代码行级别的profiling，即%lprun
%lprun[2]
lprun跟prun只有一字之差，但是功能不同——是用来统计各行代码的调用次数和时间的。
而且，前者并没有内置到python中，而且通过一个叫作line_profiler的第三方库[3]来实现的。
!pip install line_profiler
%load_ext line_profiler # 将这个模块加载到ipython kernel中
# 也可以通过改配置文件的方式，来永久地自动加载这个模块
# vi ~/.ipython/profile_default/ipython_config.py
# c.TerminalIPythonApp.extensions = ['line_profiler',]
# 参考: https://stackoverflow.com/questions/19942653/interactive-python-cannot-get-lprun-to-work-although-line-profiler-is-impor
用起来也比较直观，e.g.:
# 没有-l选项了，只有-f和-m选项
# -f func1 -f func2 -m module1 -m module2 <code to profile> 表示只统计指定的func1和func2两个函数，以及module1和module2两个模块的代码行
# 注意-f指定的必须是可以找到的函数对象，不是函数名称的子串，这一点跟prun有区别
%lprun -T ./res/lprun.txt -f Detector.score_by_sliding_window f()
结果
# 注意时间单位是默认的，最新版的line_profile支持-u选项来设置，但是还没推到pipy上
Timer unit: 1e-06 s
Total time: 0.000665 s
File: /Users/qianws/anaconda/lib/python3.5/site-packages/numpy/core/fromnumeric.py
Function: amax at line 2174
Line # Hits Time Per Hit % Time Line Contents
==============================================================
2174 def amax(a, axis=None, out=None, keepdims=np._NoValue):
2175 """
2257 ... docstring ...
2258 """
2259 100 66 0.7 9.9 kwargs = {}
2260 100 62 0.6 9.3 if keepdims is not np._NoValue:
2261 kwargs['keepdims'] = keepdims
2262
2263 100 72 0.7 10.8 if type(a) is not mu.ndarray:
2264 try:
2265 amax = a.max
2266 except AttributeError:
2267 pass
2268 else:
2269 return amax(axis=axis, out=out, **kwargs)
2270
2271 100 74 0.7 11.1 return _methods._amax(a, axis=axis,
2272 100 391 3.9 58.8 out=out, **kwargs)
Total time: 5.67407 s # 逐行统计时间本身也对耗时也干扰，这里的数字比正常运行时偏大
File: /Users/qianws/jupyterNotebooks/KWS/ctc_based_kws.py
Function: score_by_sliding_window at line 320
Line # Hits Time Per Hit % Time Line Contents
==============================================================
320 def score_by_sliding_window(self, l: List[str], P: np.ndarray) -> float:
321 """... docstring ..."""
...
335 55600 44393 0.8 0.8 for t in range(1, T):
336 542100 469812 0.9 8.3 for s in range(0, S):
...
349 487890 494446 1.0 8.7 if s >= 2 and l[s] != l[s - 2] and l[s] != '_':
350 162630 499166 3.1 8.8 a[s, t] = walk_fn([a[s, t - 1] * mut_l, a[s - 1, t - 1] * p, a[s - 2, t - 1] * p])
351 325260 255332 0.8 4.5 elif s >= 1:
352 271050 721568 2.7 12.7 a[s, t] = walk_fn([a[s, t - 1] * mut_l, a[s - 1, t - 1] * p])
353 else:
354 54210 79284 1.5 1.4 a[s, t] = mut_l * (a[s, t - 1]) # l[0]必然是blank，其概率不参与重复的连乘
...
361 1390 1314 0.9 0.0 return res
不难看出，第352行的walk_fn的调用占了12.7%的时间，是重点优点目标。
至于其内部具体哪一行慢，可以如法炮制，再跑一轮%lprun
-
API详见 http://ipython.readthedocs.io/en/stable/interactive/magics.html#magic-prun ↩
-
没有独立的API文档页，只能看docstring，详见 https://github.com/rkern/line_profiler/blob/master/line_profiler.py 第266行 ↩
