line_profiler使用装饰器(@profile)标记需要调试的函数.用kernprof.py脚本运行代码,被选函数每一行花费的cpu时间以及其他信息就会被记录下来。
安装
pip3 install Cpython
pip3 install Cython git+https://github.com/rkern/line_profiler.git
代码演示
loopdemo.py 100以内哪两个数相加等于100.
首先是没有优化过的双层循环的嵌套
@profile
def foo():
task = []
for a in range(0, 101):
for b in range(0, 101):
if a + b == 100:
task.append((a, b))
return task
@profile
def run():
for item in foo():
pass
if __name__ == '__main__':
run()
运行下面的命令
kernprof -l -v loopdemo.py
-l表示逐行分析,-v用于输出。同时会输出一个文件:juliademo.py.lprof，后期可以对.lprof文件进行分析
输出结果
Wrote profile results to loopdemo.py.lprof
Timer unit: 1e-06 s
Total time: 0.009856 s
File: loopdemo.py
Function: foo at line 1
Line # Hits Time Per Hit % Time Line Contents
==============================================================
1 @profile
2 def foo():
3 1 1.0 1.0 0.0 task = []
4
5 102 47.0 0.5 0.5 for a in range(0, 101):
6 10302 4741.0 0.5 48.1 for b in range(0, 101):
7 10201 4975.0 0.5 50.5 if a + b == 100:
8 101 91.0 0.9 0.9 task.append((a, b))
9 1 1.0 1.0 0.0 return task
Total time: 0.017778 s
File: loopdemo.py
Function: run at line 12
Line # Hits Time Per Hit % Time Line Contents
==============================================================
12 @profile
13 def run():
14 102 17747.0 174.0 99.8 for item in foo():
15 101 31.0 0.3 0.2 pass
引入kernprof.py会额外的增加是时间，但是为了检测代码每一行发生了什么，这个影响没什么，实际代码运行的时候是不带@profile装饰器的只有需要line_profiler进行逐行分析的时候才需要加。
总用时Total time: 0.017778 s
Hits是调用次数。
%Time 列告诉我们哪行代码占了它所在函数的消耗的时间百分比，可以看出在foo函数中最消耗时间的是判断a+b==100,占用了50.5%的时间。
然后我对循环部分做下面的优化其他地方不变。
for a in range(0, 101):
b = 100 - a
task.append((a, b))
return task
得到下面的结果
Wrote profile results to loopdemo.py.lprof
Timer unit: 1e-06 s
Total time: 0.000126 s
File: loopdemo.py
Function: foo at line 1
Line # Hits Time Per Hit % Time Line Contents
==============================================================
1 @profile
2 def foo():
3 1 1.0 1.0 0.8 task = []
4
5 102 33.0 0.3 26.2 for a in range(0, 101):
6 101 47.0 0.5 37.3 b = 100 - a
7 101 45.0 0.4 35.7 task.append((a, b))
8 1 0.0 0.0 0.0 return task
Total time: 0.000282 s
File: loopdemo.py
Function: run at line 11
Line # Hits Time Per Hit % Time Line Contents
==============================================================
11 @profile
12 def run():
13 102 256.0 2.5 90.8 for item in foo():
14 101 26.0 0.3 9.2 pass
可以发现总用时，循环体里代码的调用次数减少了