printデバッグ用のデコレータ関数を書いてみた

# 前書き
筆者はそこまで複雑ではないPythonのプログラムを書く際に、「わざわざIDEを起動するのも面倒だな」とvimやVisual Studio Codeなどのテキストエディタを使いがちだ。そして、それに似た心境として、「わざわざデバッガを使うのも面倒だな」と引数の値や関数呼び出しのチェックに、いわゆる`print`デバッグを使いがちである。

だが、余分な一文を挟むことになるので可読性を損なうし、コードのあちこちに散らかった`print`を削除していくのも面倒だ。

デバッガを使えば解決するということは横に置いて、どうにか`printデバッグ`の手軽さを維持しつつ、この問題を解決してみたいと思う。また、折角なのでもう少しデバッグ用の機能も追加したい。

# デコレータを活用する
前節で求めているものをまとめると『複数の関数に対して、その可読性を損なうことなく、容易に削除できるような形でデバッグ機能を追加したい』となる。Pythonにはこうした場合に適した機能としてデコレータというものがある。

筆者自身の復習も兼ねて、少しだけデコレータの解説を挟む。

### デコレータ
例えば、こんなプログラムを書きたいとする。
2つの数値が与えられ、それらを足し合わせた値を出力する。ただし、与えられた数値の和が0より小さかった場合には、0を出力する。
おおよそこのようなコードになると思う。
```python
def add(a,b):
    return a+b

def filter(sum):
    if sum < 0:
        sum = 0
    print(f'sum: {sum}')

filter(add(a=1, b=1)) 


sum: 2
```

`filter(add(...))`というのは少し読みづらい。
かと言って、`add`の返り値を変数で受け取り、`filter`の引数とするのは少し冗長な気がする。ここでデコレータを使うことで、以下のように書き換えることができる。

```python
def filter(func):
    def wrapper(*args, **kwargs):
        if (sum := func(*args, **kwargs)) < 0:
            sum = 0
        print(f'sum: {sum}')
    return wrapper

@filter
def add(a,b):
    return a+b

add(a=1, b=1)


sum: 2
```
関数を呼び出す部分が、かなりすっきりした。

デコレータとは、既存の関数に対して、そのコードを書き換えることなく機能を追加する仕組みである。
前述のコードでは、
- デコレータ関数`filter`は関数を引数`func`として取り、関数内関数`wrapper`を返す。
- `wrapper`は`func（つまり、add(a=1, b=1）`の引数を`*args, **kwargs`という引数として持つ。
- `func`を実行し、その結果を得るに加えて、追加したい機能のコード（この場合ならば、`add`の返り値をチェックし、その値を書き換え、出力する）が実行される。

`@filter`と記述することで、`add`が呼び出される際には`add`を引数とする`filter`が実行されることになる。つまり`filter(add(...))`のシンタックスシュガーであり、動作的には等価だ。

### 書いてみる
では実際に、デコレータを用いてデバッグ用の関数を実装してみる。

```python
from collections.abc import Callable
from functools import wraps
from typing import TypeVar

R = TypeVar('R')

def debug(func: Callable[..., R]) -> Callable[..., R]:
    @wraps(func)
    def wrapper(*args, **kwargs):
        if any(args):
            print(f'[Args]  : {args}')
        else:
            print('[Args]  : None')

        if any(kwargs):
            print('[kwArgs]:', end=' ')
            for key, val in kwargs.items():
                print(f'{key}={val}', end=', ')
            print()
        else:
            print('[kwArgs]: None')

        return func(*args, **kwargs)
    return wrapper

@debug
def hoge(msg: str, count: int) -> None:
    print(f'{msg*count}')

hoge('hoge', count=2)


# [Args]  : ('hoge',)
# [kwArgs]: count=2, 
# hogehoge
```
型ヒントは趣味。


# 呼び出し元の情報を取得する

ある関数をデバッグするとき、その関数はどこから呼び出されたのか（ファイル名や行番号、名前空間）を表示すれば、コードの修正にかかる手間を減らすことができる。
この情報にアクセスする手段として、標準モジュール`inspect`を使用してみる。
```python
import inspect

c_frame = inspect.currentframe()
```
上のコードは、実行位置のフレームオブジェクトを取得している。
プログラムの実行中にサブルーチンを呼び出した場合、処理はそのサブルーチンに移動する。そして、サブルーチンの処理が終わると、サブルーチンを呼び出した元の位置から処理が再開される。このとき、サブルーチンから元のルーチンのどこに戻ればいいのか覚えている必要があり、コールスタックにそうした呼び出し実行時の情報が保存されている。
フレームオブジェクトはこの実行時の情報にあたり、`inspect.currentframe()`は呼び出し元（実行しているフレーム）のフレームオブジェクトを返す。

フレームオブジェクトが持つ情報を[公式ドキュメント](https://docs.python.org/ja/3/library/inspect.html#types-and-members)からいくつか並べてみる。
| 属性      | 説明 |
| ----     | ---- |
|f_back    |    外側 (このフレームを呼び出した) のフレームオブジェクト|
|f_builtins|	このフレームで参照している組み込み名前空間|
|f_code    |	このフレームで実行しているコードオブジェクト|
|f_globals |	このフレームで参照しているグローバル名前空間|
|f_lineno  |	現在の Python ソースコードの行番号|
|f_locals  |	このフレームで参照しているローカル名前空間|

ここでは、デバッグ関数を呼び出した時の情報を得るためにフレームレコードを使用する。
フレームレコードとは`FrameInfo(frame, filename, lineno, function, code_context, index)`というnamed tupleで、今回求めている「ファイル名」「実行中の行番号」「関数名」を取得することができる。

`inspectt.getouterframes(frame)`は`frame`で指定したフレームとそのフレームの外側のフレームのフレームレコードのリストを返す。リストの先頭は`frame`のフレームレコードで、末尾は`frame`から最も外側のフレーム（`frame`が生成されるまでの関数呼び出しの起点）となる。

少しややこしいので、コードにしてみる。

```python
import inspect

def A():
    B()

def B():
    C()

def C():
    frame = inspect.currentframe()
    frame_list = inspect.getouterframes(frame)
    print(frame_list[0].frame)
    print(frame_list[1].frame)
    print(frame_list[2].frame)
    print(frame_list[3].frame)

A()


# <frame at 0x00000231574011B0, file '...\\sample.py', line 12, code C>
# <frame at 0x000002315736B440, file '...\\sample.py', line 7, code B>
# <frame at 0x000002315736ED40, file '...\\sample.py', line 4, code A>
# <frame at 0x0000023157369E40, file '...\\sample.py', line 17, code <module>>
```

1. 関数Aを呼び出す。
2. 関数Aから関数Bを呼び出す。
3. 関数Bから関数Cを呼び出す。
4. 関数Cを`frame`として`inspect.getouterframes()`を実行する。
フレームレコードのリストは先頭からC、B、A、moduleとなっている。

では、関数の呼び出し位置（ファイル名と行番号、関数名（というより名前空間？））を出力するコードを書いてみる。
```python: sample.py
import inspect
from os.path import basename

def func():
    frame = inspect.currentframe().f_back
    o_frame = inspect.getouterframes(frame)[0]
    file = basename(o_frame.filename)
    line = o_frame.lineno
    code = o_frame.function
    print(f'[Caller]: File {file}, line {line}, in {code}')

func()


#[Caller]: File sample.py, line 12, in <module>

```

よく見る形式で、`func()`が呼び出されているファイル名、行番号、名前空間を表示できた。
これをデバッグ関数に追記して完成。

```python
import inspect
from collections.abc import Callable
from functools import wraps
from os.path import basename
from typing import TypeVar

R = TypeVar('R')

def debug(func: Callable[..., R]) -> Callable[..., R]:
    @wraps(func)
    def wrapper(*args, **kwargs):
        frame = inspect.currentframe().f_back
        o_frame = inspect.getouterframes(frame)[0]
        file = basename(o_frame.filename)
        line = o_frame.lineno
        code = o_frame.function
        print(f'[Caller]: File {file}, line {line}, in {code}')

        if any(args):
            print(f'[Args]  : {args}')
        else:
            print('[Args]  : None')

        if any(kwargs):
            print('[kwArgs]:', end=' ')
            for key, val in kwargs.items():
                print(f'{key}={val}', end=', ')
            print()
        else:
            print('[kwArgs]: None')

        return func(*args, **kwargs)
    return wrapper

@debug
def hoge(msg: str, count: int) -> None:
    print(f'{msg*count}')

hoge('hoge', count=2)


# [Caller]: File sample.py, line 37, in <module>
# [Args]  : ('hoge',)
# [kwArgs]: count=2,
# hogehoge
```