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
可以發現總用時，循環體里代碼的調用次數減少了