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

前書き

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

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

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

デコレータを活用する

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

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

デコレータ

例えば、こんなプログラムを書きたいとする。
2つの数値が与えられ、それらを足し合わせた値を出力する。ただし、与えられた数値の和が0より小さかった場合には、0を出力する。
おおよそこのようなコードになると思う。

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の引数とするのは少し冗長な気がする。ここでデコレータを使うことで、以下のように書き換えることができる。

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(...))のシンタックスシュガーであり、動作的には等価だ。

書いてみる

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

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を使用してみる。

import inspect

c_frame = inspect.currentframe()

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

フレームオブジェクトが持つ情報を公式ドキュメントからいくつか並べてみる。

属性	説明
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が生成されるまでの関数呼び出しの起点）となる。

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

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となっている。

では、関数の呼び出し位置（ファイル名と行番号、関数名（というより名前空間？））を出力するコードを書いてみる。

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()が呼び出されているファイル名、行番号、名前空間を表示できた。
これをデバッグ関数に追記して完成。

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