LoginSignup
79
66

More than 3 years have passed since last update.

@aratana_tamutomoin株式会社ZOZO

Pythonのline_profilerとmemory_profilerの紹介

Last updated at Posted at 2018-12-14

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()

さいごに

簡単に処理時間やメモリ量を行単位で確認することができるようになれたかと思います！
他にも様々なプロファイラーがありますので、それぞれの長所や短所を見つけ、
使いこなせるようになると、さらによくなりそうです。

79
66
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
79
66