テスト中だけデバッグ出力をONにして内容をテスト

テスト対象の中のprivateな値が期待通りに変化していることをgetterを作って晒したりせずに確認する、というのをやってみた。with構文を使ってテストの間だけ一時的なログハンドラを貼り付けてやってる。doctestに書いてあるように普通にCounter().push()した時には何も表示されないが、with TemporaryLogHandler(__name__)で囲うとログが出力されるようになる。

"""
>>> Counter().push()

>>> from templog import TemporaryLogHandler
>>> with TemporaryLogHandler(__name__):
...     Counter().push()
current value: 0
value changed to: 1
"""
import logging
logger = logging.getLogger(__name__)


class Counter(object):
    def __init__(self):
        self.__value = 0

    def push(self):
        logger.debug("current value: %s", self.__value)
        self.__value += 1
        logger.debug("value changed to: %s", self.__value)


def _test():
    import doctest
    doctest.testmod()


if __name__ == "__main__":
    _test()

実装はこんな感じ。StreamHandlerでログ出力を標準出力に出すようにして、doctestでそれをテストしている。もちろんユニットテスト的なことがしたいのであればcStringIO.StringIOに出力するようにしてその値をテストしても良いだろうと思う。

import sys

class TemporaryLogHandler(object):
    def __init__(self, logger_name):
        self.logger_name = logger_name

    def __enter__(self):
        self.handler = logging.StreamHandler(sys.stdout)
        self.handler.setLevel(logging.DEBUG)
        logger = logging.getLogger(self.logger_name)
        self.old_level = logger.level
        logger.setLevel(logging.DEBUG)
        logger.addHandler(self.handler)

    def __exit__(self, *args):
        logger = logging.getLogger(self.logger_name)
        logger.removeHandler(self.handler)
        logger.setLevel(self.old_level)

この状態では別のログを出してもそのログがハンドラに拾われてしまってテストがfailするようになるから、テストに使う出力はテスト用のロガーに出したほうがいいのかもしれないなぁ。