pythonでテストケース用のロガーを自作する - pyopyopyo - Linuxとかプログラミングの覚え書き -

pythonでテストケース用のロガーを自作したので公開します

テスト関数にデコレータを付けるだけで，成功／失敗を記録するロガーを作りました．最小実装なので，好みに合わせて拡張できます．

ロガー本体のコードは末尾に掲載します．先に使い方から説明します．

使い方（その１）

ある関数 f に対して，テスト関数 test_simple を用意し，その引数と成功・失敗をログに出します．

# 自作ロガーをimport
from testcase import testcase

# テスト対象の関数
def f(x,y):
    return x+y

# テストケース．"@testcase()”がデコレータ
@testcase()
def test_simple(x, y,  expected):
   return f(x, y) == expected

test_simple(1,2, 3) # f(1, 2)==3なので，これは成功
test_simple(2,4, 6) # f(2,4)==6なので，これも成功
test_simple(2,4, 4) #  これは失敗する

実行すると以下の出力が得られます

  OK test_simple(x=1, y=2, expected=3)  [0.00 msec]
  OK test_simple(x=2, y=4, expected=6)  [0.00 msec]
* NG test_simple(x=2, y=4, expected=4)  [0.00 msec]

先頭が NGで始まるテストケースは失敗を意味しています
末尾の [0.00 msec]は実行時間を表します

使い方（その２）

テストには次の2種類があります．

expected_success：通ることを期待するテスト
expected_failure：通らないことを期待するテスト（既知のバグなど）

上記の使い方（その１）は，expected_successのテストでした

expected_successとexpected_failureを使い分けるには次のようなコードを書きます

@testcase(expected_success=True)
def  test_expected_success(x, y):
      return f(x,y) == x+y

@testcase(expected_success=False)
def  test_expected_failure(x, y):
      return f(x,y) == x-y  


test_expected_success(1,2)
test_expected_success(3,4)
test_expected_success(0,0)

test_expected_failure(1,2)
test_expected_failure(3,4)
test_expected_failure(0,0)

  OK test_expected_success(x=1, y=2)  [0.00 msec]
  OK test_expected_success(x=3, y=4)  [0.00 msec]
  OK test_expected_success(x=0, y=0)  [0.00 msec]
  OK test_expected_failure(x=1, y=2)  [0.00 msec]
  OK test_expected_failure(x=3, y=4)  [0.00 msec]
* NG test_expected_failure(x=0, y=0)  [0.00 msec]

test_expected_failure(x, y) は式 x + y == x - y を評価し，Falseなら成功（OK），Trueなら失敗（NG）と判定します．
x + y == x - y は常にFalse……と見落としがちですが，x = y = 0 のときだけ True になるため，このケースは expected_failure で NG になります．

ポイント

このように，デコレータを付けるだけで，引数・実行結果・実行時間を一行で出力できます

また最小構成なので，出力先（標準出力／ファイル），色付け，集計（合計OK/NG，総時間）などが容易に拡張可能です．

ソースコード

import logging
import inspect
from functools import wraps
import time

logging.basicConfig(
    level=logging.INFO,
    format="%(message)s"
)
log = logging.getLogger("testcase")

def testcase(expected_success:bool = True):
    """
    """
    def decor(func):
        sig = inspect.signature(func)

        @wraps(func)
        def wrapper(*args, **kwargs):
            # 引数のログ
            bound = sig.bind_partial(*args, **kwargs)
            bound.apply_defaults()
            arg_str = ", ".join(f"{k}={repr(v)}" for k, v in bound.arguments.items())


            status = False
            t0 = time.perf_counter()
            try:
                result = bool(func(*args, **kwargs))
            except Exception as e:
                log.error(f"EXCEPTION in {func.__name__}: {e}")
            else:
                # 判定
                if expected_success:
                    status = (result is True)
                else:
                    status = (result is False)
            finally:
                delta_ms = (time.perf_counter() - t0) * 1000.0

            code = "  OK" if status else "* NG"
            log.info('%s %s(%s)  [%.2f msec]' % (code, func.__name__, arg_str, delta_ms))

            return status

        return wrapper
    return decor