line_profiler
指定した関数やクラス内ソースの、行ごとの実行回数や、処理時間を行単位で計測してくれる便利ツール。
導入方法
pip install line_profiler
※下記サンプルコードで確認していきますが、リスト内包表記は使わないです。
profileデコレータを使用する方法もありますが、汎用性無いと思ったので紹介しません。
Python3.7
2019/10/02現状、上記方法ではインストールができなかった。
下記方法でインストールできました。
git clone https://github.com/rkern/line_profiler.git
cd line_profiler
pip install cython
pip install .
通常の実行
from line_profiler import LineProfiler
LEN = 10000
# ひどいコード
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
prof = LineProfiler()
prof.add_function(hoge)
prof.runcall(hoge)
prof.print_stats()
output
Timer unit: 1e-06 s # 処理時間の単位
Total time: 0.007426 s # 合計処理時間
File: profiler.py # 実行ファイル名
Function: hoge at line 7 # 関数宣言位置
Line # Hits Time Per Hit % Time Line Contents
==============================================================
# 行数 実行回数 合計 一回毎 関数内 コード！
# 処理時間 平均処理時間 処理時間割合 コード！
7 def hoge():
8 1 7.0 7.0 0.1 a = []
9 10001 3240.0 0.3 43.6 for i in range(LEN):
10 10000 4179.0 0.4 56.3 a.append(i * i)
11 1 0.0 0.0 0.0 return a
処理時間表示の精度を変更
prof.print_statsの引数output_unitを設定するだけです。
# output_unitを設定する（単位が、1e-9となる）
prof.print_stats(output_unit=1e-9)
output
Timer unit: 1e-09 s # ←単位変わってますね
Total time: 0.008005 s
File: profiler.py
Function: hoge at line 7
# ↓より細かく確認できますね
Line # Hits Time Per Hit % Time Line Contents
==============================================================
7 def hoge():
8 1 7000.0 7000.0 0.1 a = []
9 10001 3422000.0 342.2 42.7 for i in range(LEN):
10 10000 4575000.0 457.5 57.2 a.append(i * i)
11 1 1000.0 1000.0 0.0 return a
100回実行して平均見てみる
100回実行するだけです。
from line_profiler import LineProfiler
LEN = 10000
# ひでーコード
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
prof = LineProfiler()
prof.add_function(hoge)
# 100回実行
for _ in range(100):
prof.runcall(hoge)
prof.print_stats(output_unit=1e-9)
output
Timer unit: 1e-09 s
Total time: 0.716419 s
File: profiler.py
Function: hoge at line 7
Line # Hits Time Per Hit % Time Line Contents
==============================================================
7 def hoge():
8 100 87000.0 870.0 0.0 a = []
9 1000100 304378000.0 304.3 42.5 for i in range(LEN):
10 1000000 411898000.0 411.9 57.5 a.append(i * i)
11 100 56000.0 560.0 0.0 return a
勝手に平均計算してくれるので、楽ですね。
コードを修正して比較
試しに、関数の参照を省略することによる高速化してみます。
output
Timer unit: 1e-09 s
Total time: 0.695787 s
File: profiler.py
Function: hoge at line 7
Line # Hits Time Per Hit % Time Line Contents
==============================================================
7 def hoge():
8 100 95000.0 950.0 0.0 a = []
9 #ここらへん修正---> # append関数を一時変数に
10 100 79000.0 790.0 0.0 a_append = a.append
11 1000100 313700000.0 313.7 45.1 for i in range(LEN):
12 1000000 381867000.0 381.9 54.9 a_append(i * i)
13 100 46000.0 460.0 0.0 return a
多少の誤差はあるかと思いますが、12行目の一回平均処理時間が、
30ナノ秒ぐらい早くなってますね。（ちりつもやまとなでこ！）
結果をファイルに出力
stream設定してあげれば、出力先変更できます。
with open('line_profiler.log', 'w') as f:
prof.print_stats(stream=f)
クラスに対しても、ラインプロファイラー
# こんな感じ。後はいつものように、runcall!
prof.add_module(Hoge)
詳しくは、
パフォーマンスチューニングでprofiler使わないのは損してると思うPython
memory_profiler
簡単に説明すると、line_profilerのメモリ版。
行単位でメモリの増減を計測できる。
計測時間結構かかる気がする。。。
導入方法
pip install memory_profiler
# 処理速度を上げるためにpsutil
pip install psutil
通常の実行
ある一行ですんごいメモリ量を見つかったら、ジェネレータを検討するなり、いろいろ対策へ移れるかと思います。
from memory_profiler import profile
LEN = 10000
@profile
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
output
Filename: profiler.py
# 現在の合計 増分 コード！
# メモリ使用量 メモリ使用量 コード！
Line # Mem usage Increment Line Contents
================================================
7 37.4 MiB 37.4 MiB @profile
8 def hoge():
9 37.4 MiB 0.0 MiB a = []
10 38.1 MiB 0.0 MiB for i in range(LEN):
11 38.1 MiB 0.6 MiB a.append(i * i)
12 38.1 MiB 0.0 MiB return a
もっとメモリ表示の精度をあげる
# precisionを設定する
@profile(precision=4)
def hoge():
~~
output
Filename: profiler.py
Line # Mem usage Increment Line Contents
================================================
7 37.3672 MiB 37.3672 MiB @profile(precision=4)
8 def hoge():
9 37.3672 MiB 0.0000 MiB a = []
10 37.9531 MiB 0.0000 MiB for i in range(LEN):
11 37.9531 MiB 0.5859 MiB a.append(i * i)
12 37.9531 MiB 0.0000 MiB return a
デコらない、メモリプロファイラ
from memory_profiler import profile
LEN = 10000
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
profile(hoge)()
結果をファイルに出力
line_profilerと同じように、stream設定してあげれば、出力先変更できます。
with open('line_profiler.log', 'w') as f:
profile(hoge, stream=f)()
mprof
処理時間とメモリ量増加の推移をプロットしてくれるツールです。
詳しくは、
Python: memory_profiler でプログラムのメモリ使用量を調べる
Deloggerにプロファイラー用デコレータ追加してみた
自分がいつも使ってる、ロギングツールDeloggerで楽に、行単位の処理時間と使用メモリ量をログに起こせるようにしました！
Deloggerなんやそれ？って方は、私が書いたPythonロギングを（主に自分が）快適になるDeloggerプラグインを是非。
line_profile
from delogger.presets.profiler import logger
LEN = 10000
@logger.line_profile
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
output
DEBUG [_debugger_l File "logger.py", line 298, in wrapper] line_profiler result
Timer unit: 1e-06 s
Total time: 0.006579 s
File: profiler.py
Function: hoge at line 11
Line # Hits Time Per Hit % Time Line Contents
==============================================================
11 @Delogger.line_profiler
12 def hoge():
13 1 1.0 1.0 0.0 a = []
14 10001 2868.0 0.3 43.6 for i in range(LEN):
15 10000 3709.0 0.4 56.4 a.append(i * i)
16 1 1.0 1.0 0.0 return a
Delogger 0.2.4バージョン以下
from delogger import Delogger
Delogger.is_debug_stream = True
LEN = 10000
@Delogger.line_profiler
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
memory_profile
from delogger.presets.profiler import logger
LEN = 10000
@logger.memory_profile
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
output
DEBUG [_debugger_m File "logger.py", line 316, in wrapper] memory_profiler result
Filename: profiler.py
Line # Mem usage Increment Line Contents
================================================
8 47.82 MiB 47.82 MiB @Delogger.memory_profiler
9 def hoge():
10 47.82 MiB 0.00 MiB a = []
11 48.10 MiB 0.00 MiB for i in range(LEN):
12 48.10 MiB 0.28 MiB a.append(i * i)
13 48.10 MiB 0.00 MiB return a
Delogger 0.2.4バージョン以下
from delogger import Delogger
Delogger.is_debug_stream = True
LEN = 10000
@Delogger.memory_profiler
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
あることに気づいた
ここまで、まとめてみましたが、処理時間とメモリ使用量両方みれたほうが便利な時と思いました。
例えば、メモリ量減らすことできたが、処理時間増えちゃったとか。（これはmprofで確認できるのかな？）
と投稿前日に思い立って、
いい感じに合体してくれるやつ作ってみました。
line_profiler, memory_profiler合体（Deloggerで）
勢いで作りました。
内部では、line_profiler, memory_profiler両方実行して、結果をいい感じに加工してます。
from delogger.presets.profiler import logger
LEN = 10000
@logger.line_memory_profile
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
output
DEBUG [_debugger_l_m File "logger.py", line 351, in wrapper] line, memory profiler result
Timer unit: 1e-06 s
Total time: 0.006418 s
File: profiler.py
Function: hoge at line 8
Line # Hits Time Per Hit % Time Mem usage Increment Line Contents
=========================================================================================
8 47.78 MiB 47.78 MiB @Delogger.line_memory_profiler
9 def hoge():
10 1 1.0 1.0 0.0 47.78 MiB 0.00 MiB a = []
11 10001 2885.0 0.3 45.0 48.05 MiB 0.00 MiB for i in range(LEN):
12 10000 3532.0 0.4 55.0 48.05 MiB 0.28 MiB a.append(i * i)
13 1 0.0 0.0 0.0 48.05 MiB 0.00 MiB return a
Delogger 0.2.4バージョン以下
from delogger import Delogger
Delogger.is_debug_stream = True
LEN = 10000
@Delogger.line_memory_profiler
def hoge():
a = []
for i in range(LEN):
a.append(i * i)
return a
hoge()
さいごに
簡単に処理時間やメモリ量を行単位で確認することができるようになれたかと思います！
他にも様々なプロファイラーがありますので、それぞれの長所や短所を見つけ、
使いこなせるようになると、さらによくなりそうです。