Go to Qiita Advent Calendar 2024 Top
LoginSignup
0
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

開志専門職大学情報学部Advent Calendar 2023Day 1
@khrive

プログラムの挙動を知るための自動トレース,自動ロギング

Posted at

はじめに

　働き方改革とタイパの時代，初見コードの理解もできるだけ時短して，可処分時間（自由時間）を増やしましょう．
　難解なコードの意味はコードに聞いて，プログラムのざっくりした挙動もコードに語ってもらいましょう．
　とはいえ，デバッグのためにprint文のコピペを繰り返すのは，煩雑な仕事を増やし時短的にNGです．そもそも，無節操なコードクローンはイマイチです．
　そこで，関数やメソッド呼び出しを自動ロギング，自動トレースする方法を試します．

動作環境

MacOS sonoma 14.1.2, JupyterLab
Python 3.8.13
pip 23.3.1

説明の順序

  1. trace.Traceを使う
  2. 通常のメソッド実行の例題
  3. 自動ロギングの実装例(インスタンスメソッドのトレース)
  • メソッド呼び出しをフックする： メソッドのラップ関数
  1. 自動ロギングの実装例(スタティックメソッドのトレース)
  2. メタクラスのトレース（メタメタクラス,自己循環メタクラス化？）

trace.Trace

traceモジュール1を使う方法の簡単な事例です．

import trace
def factorial(n):
    return 1 if n==0 else n * factorial(n-1)

tracer = trace.Trace(count=True, trace=True)
tracer.runfunc(factorial, 4)

通常のメソッド実行の例題

普通のメソッド実行の事例です．まだ自動ロギング，自動トレースはありません．

# 通常のクラス設計
class Hanoi():
    def move(self,n,A,B,C):
        if n>0:
            self.move(n-1,A,C,B)
            print(f'Move #[{n}]@{A}　->　#[{n}]{B}')
            self.move(n-1,C,B,A)
# インスタンスメソッド呼び出し
hanoi = Hanoi()
hanoi.move(3,'左','中','右')
  • 実行結果
Move #[1]@左　->　#[1]中
Move #[2]@左　->　#[2]右
Move #[1]@中　->　#[1]右
Move #[3]@左　->　#[3]中
Move #[1]@右　->　#[1]左
Move #[2]@右　->　#[2]中
Move #[1]@左　->　#[1]中

以降，自動ロギングを追加していきます．

自動ロギングの実装例(インスタンスメソッドのトレース）

インスタンスメソッドの実行を契機に，自動でログを出力させます．
ここでは，時系列の順序を正しくトレースするために，ログをstderrに分離せずに，
通常の出力に混ぜ込むように，stdoutに出力してみます．

import sys
import logging

# 自動ロギングのレベル設定， 出力設定: sys.stdoutに通常出力と同期
logging.basicConfig(level=logging.DEBUG, stream=sys.stdout)
    
# 自動ロギング用メタクラス
class LoggingMeta(type):
    def __new__(cls, klass, bases, attrs):
        def wrap(method):      # オリジナルメソッドをラップする関数
            def wrapper(*args, **kwargs):    # 自動ロギング
                logging.debug(f"=> {klass}#{method.__name__} with (args={args}, kwargs={kwargs})")
                return method(*args, **kwargs)  # オリジナルのメソッド実行
            return wrapper
        _methods = { k:v for k,v in attrs.items() if callable(v) }  # klassの全メソッド
        for name, method in _methods.items(): 
            attrs[name] = wrap(method) # オリジナルメソッドをwrapして書き換える
        # メタクラスの__new__() -> クラス生成
        return super().__new__(cls, klass, bases, attrs)

# 自動ロギング用メタクラスに書き換え
class Hanoi(metaclass=LoggingMeta):
    def move(self,n,A,B,C):
        if n>0:
            self.move(n-1,A,C,B)
            print(f'Move #[{n}]@{A}　->　#[{n}]{B}')
            self.move(n-1,C,B,A)
# インスタンスメソッド呼び出し
hanoi = Hanoi()    
hanoi.move(3,'左','中','右')
  • 実行結果（動作確認）
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 3, '左', '中', '右'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 2, '左', '右', '中'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 1, '左', '中', '右'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '左', '右', '中'), kwargs={})
Move #[1]@左　->　#[1]中
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '右', '中', '左'), kwargs={})
Move #[2]@左　->　#[2]右
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 1, '中', '右', '左'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '中', '左', '右'), kwargs={})
Move #[1]@中　->　#[1]右
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '左', '右', '中'), kwargs={})
Move #[3]@左　->　#[3]中
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 2, '右', '中', '左'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 1, '右', '左', '中'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '右', '中', '左'), kwargs={})
Move #[1]@右　->　#[1]左
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '中', '左', '右'), kwargs={})
Move #[2]@右　->　#[2]中
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 1, '左', '中', '右'), kwargs={})
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '左', '右', '中'), kwargs={})
Move #[1]@左　->　#[1]中
DEBUG:root:=> Hanoi#move with (args=(<__main__.Hanoi object at 0x7facb829f820>, 0, '右', '中', '左'), kwargs={})

自動ロギングの実装例(スタティックメソッドのトレース)

スタティックメソッド(@staticmethodでデコレート)の実行を契機に，ログを出力させます．
クラスメソッド（@classmethodでデコレート）は，主にコンストラクタの代替に活用し，
第一パラメタにcls（クラス）を取りますが，スタティックメソッドは，クラス内で定義した
普通の関数と変わらず第一引数にclsやselfは取りません．

import sys
import logging

# 自動ロギングのレベル設定， 出力設定: sys.stdoutに通常出力と同期
logging.basicConfig(level=logging.DEBUG, stream=sys.stdout)

class LoggerMeta(type):
    def __new__(cls, klass, bases, attrs):
        for k,v in attrs.items():
            if isinstance(v,staticmethod):
                def alt_method(*args, **kwargs):
                    logging.info(f'Static method {v}#{klass} called with args: {args} kwargs: {kwargs}')
                    return v.__func__(*args, **kwargs)
                attrs[k] = staticmethod(alt_method)
        return type.__new__(cls, klass, bases, attrs)
    
class Hanoi(metaclass=LoggerMeta):
    @staticmethod
    def move(n,A,B,C):
        if n>0:
            Hanoi.move(n-1,A,C,B)
            print(f'Move #[{n}]@{A}　->　#[{n}]{B}')
            Hanoi.move(n-1,C,B,A)

Hanoi.move(3,'左','中','右')
  • 実行結果（動作確認）
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (3, '左', '中', '右') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (2, '左', '右', '中') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (1, '左', '中', '右') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '左', '右', '中') kwargs: {}
Move #[1]@左　->　#[1]中
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '右', '中', '左') kwargs: {}
Move #[2]@左　->　#[2]右
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (1, '中', '右', '左') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '中', '左', '右') kwargs: {}
Move #[1]@中　->　#[1]右
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '左', '右', '中') kwargs: {}
Move #[3]@左　->　#[3]中
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (2, '右', '中', '左') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (1, '右', '左', '中') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '右', '中', '左') kwargs: {}
Move #[1]@右　->　#[1]左
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '中', '左', '右') kwargs: {}
Move #[2]@右　->　#[2]中
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (1, '左', '中', '右') kwargs: {}
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '左', '右', '中') kwargs: {}
Move #[1]@左　->　#[1]中
INFO:root:Static method <staticmethod object at 0x7f965042f970>#Hanoi called with args: (0, '右', '中', '左') kwargs: {}

メタクラスの挙動トレース：　自己循環メタクラス化

　LoggingMetaがひとたび定義されて実行できたならば，LoggingMeta自身の挙動をトレースすることも可能です．つまり，メタクラス自身の挙動をトレースするために，一度定義したメタクラスを自身のメタクラスに設定する実験です．メタクラス循環の入り口を見ることができるかもしれません．

class LoggingMeta(type,metaclass=LoggingMeta):
    def __new__(cls, klass, bases, attrs):
        def wrap(method):      # オリジナルメソッドをラップする関数
            def wrapper(*args, **kwargs):    # 自動ロギング
                logging.debug(f"=> {klass}#{method.__name__} with (args={args}, kwargs={kwargs})")
                return method(*args, **kwargs)  # オリジナルのメソッド実行
            return wrapper
        _methods = { k:v for k,v in attrs.items() if callable(v) }  # klassの全メソッド
        for name, method in _methods.items(): 
            attrs[name] = wrap(method) # オリジナルメソッドをwrapして書き換える
        # メタクラスの__new__() -> クラス生成
        return super().__new__(cls, klass, bases, attrs)

class Hanoi(metaclass=LoggingMeta):
    pass
  • 実行結果（動作確認）
DEBUG:root:=> LoggingMeta#__new__ with (args=(<class '__main__.LoggingMeta'>, 'LoggingMeta', (<class 'type'>,), {'__module__': '__main__', '__qualname__': 'LoggingMeta', '__new__': <function LoggingMeta.__new__ at 0x7ff4983ca280>, '__classcell__': <cell at 0x7ff4a9fa9d60: empty>}), kwargs={})
DEBUG:root:=> LoggingMeta#__new__ with (args=(<class '__main__.LoggingMeta'>, 'Hanoi', (), {'__module__': '__main__', '__qualname__': 'Hanoi'}), kwargs={})

おわりに

　初見のコードや難解なコードを時短で理解するいくつかの方法を試しました．
初学者には難解と思しき，再帰関数（メソッド）呼び出しを題材としていますが，トレースするとますます難解になる危険性を含みます．再帰関数の理解は，手順を追わずに，宣言的な知識として受け取るほうがよいでしょう．未来に完成する機能は，少し前の未来の機能を借用して実現できているエクスペクトパトローナム風解釈で，硬く考えずにコードを読んでみるのもまた楽しからずやです．
　最後に，メタクラス自身の挙動をトレースするために，一度定義したメタクラスを自身のメタクラスに設定できることが確認とれました．メタクラスの循環化の入り口が見えてきたでしょうか．

  1. (https://docs.python.org/ja/3/library/trace.html) ↩

0
5
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
0
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?