Pythonのline_profilerとmemory_profilerの紹介

# line_profiler
指定した関数やクラス内ソースの、行ごとの実行回数や、処理時間を**行単位**で計測してくれる便利ツール。


## 導入方法

```bash
pip install line_profiler
```

*※下記サンプルコードで確認していきますが、リスト内包表記は使わないです。
profileデコレータを使用する方法もありますが、汎用性無いと思ったので紹介しません。*

### Python3.7
`2019/10/02`現状、上記方法ではインストールができなかった。
下記方法でインストールできました。

```bash
git clone https://github.com/rkern/line_profiler.git
cd line_profiler
pip install cython
pip install .
```

## 通常の実行

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

```python: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`を設定するだけです。

```python
# output_unitを設定する（単位が、1e-9となる）
prof.print_stats(output_unit=1e-9)
```

```python: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回実行するだけです。

```python
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)
```

```python: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
```

勝手に平均計算してくれるので、楽ですね。

### コードを修正して比較
試しに、関数の参照を省略することによる高速化してみます。

```python: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`設定してあげれば、出力先変更できます。

```python
with open('line_profiler.log', 'w') as f:
    prof.print_stats(stream=f)
```

## クラスに対しても、ラインプロファイラー
```python
# こんな感じ。後はいつものように、runcall!
prof.add_module(Hoge)
```
詳しくは、

[パフォーマンスチューニングでprofiler使わないのは損してると思うPython](https://qiita.com/haminiku/items/eab2a57ffb1bb207c89c)


# memory_profiler
簡単に説明すると、line_profilerのメモリ版。
行単位でメモリの増減を計測できる。
*計測時間結構かかる気がする。。。*

## 導入方法

```bash
pip install memory_profiler
# 処理速度を上げるためにpsutil
pip install psutil
```

## 通常の実行
ある一行ですんごいメモリ量を見つかったら、ジェネレータを検討するなり、いろいろ対策へ移れるかと思います。

```python
from memory_profiler import profile

LEN = 10000


@profile
def hoge():
    a = []
    for i in range(LEN):
        a.append(i * i)
    return a


hoge()
```

```python: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
```

## もっとメモリ表示の精度をあげる

```python
# precisionを設定する
@profile(precision=4)
def hoge():
    ~~
```

```python: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
```


## デコらない、メモリプロファイラ

```python
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`設定してあげれば、出力先変更できます。

```python
with open('line_profiler.log', 'w') as f:
    profile(hoge, stream=f)()
```

## mprof
処理時間とメモリ量増加の推移をプロットしてくれるツールです。
詳しくは、
[Python: memory_profiler でプログラムのメモリ使用量を調べる](https://blog.amedama.jp/entry/2018/02/04/001950)

# Deloggerにプロファイラー用デコレータ追加してみた
自分がいつも使ってる、ロギングツール[Delogger](https://github.com/deresmos/delogger)で楽に、行単位の処理時間と使用メモリ量をログに起こせるようにしました！
Deloggerなんやそれ？って方は、私が書いた[Pythonロギングを（主に自分が）快適になるDeloggerプラグイン](https://qiita.com/deresmos/items/0868a2cf18837c3f3f2a)を是非。

## line_profile

```python

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

```

```python: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

```

<details><summary>Delogger 0.2.4バージョン以下</summary><div>

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

</div></details>


## memory_profile

```python

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

```

```python: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
```

<details><summary>Delogger 0.2.4バージョン以下</summary><div>

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

```

</div></details>

## あることに気づいた
ここまで、まとめてみましたが、処理時間とメモリ使用量両方みれたほうが便利な時と思いました。
例えば、メモリ量減らすことできたが、処理時間増えちゃったとか。（これはmprofで確認できるのかな？）
と投稿前日に思い立って、
いい感じに合体してくれるやつ作ってみました。

## line_profiler, memory_profiler合体（Deloggerで）
勢いで作りました。
内部では、line_profiler, memory_profiler両方実行して、結果をいい感じに加工してます。

```python

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

```

```python: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
```

<details><summary>Delogger 0.2.4バージョン以下</summary><div>

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

</div></details>

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