Pythonでログ出力をテストするLogCaptureを使ってみた

少し細かいですが、「このソースコードは意図したとおりにログ出力するのか？？」を単体テストレベルでちゃんと確認しておくことで、品質の向上に繋がります。

今回はtestfixturesのLogCaptureを試してみました。使い方はこちらのドキュメントを参考にしました。

※pytestを使っている場合は、こちらのブログで紹介されているLogCaptureFixtureを使っても良いと思います。

セットアップ

• バージョン

$ python --version
Python 3.6.9

• ライブラリインストール

pip install pytest testfixtures

コード

ソースコード（src/main.py）

import json
import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

def main(is_error):
    logger.debug('Hello World.')
    logger.info('Function called.')
    if is_error:
        logger.error('Error occurred.')

テストコード（test/test_main.py）

import pytest
import logging
from testfixtures import LogCapture
from src.main import main


@pytest.fixture(scope='function')
def mock_logger():
    with LogCapture() as log:
        yield log

class TestClass:
    def test_logging(self, mock_logger):
        main(is_error=False)
        print(main)

テスト実行

$ python -m pytest test/test_main.py -s
...省略
collected 1 item
test/test_main.py::TestClass::test_logging <- unit/test_main.py

src.main DEBUG
  Hello World.
src.main INFO
  Function called.
PASSED

いろいろ試してみる

ログ出力のテスト

...省略
    def test_logging_1(self, mock_logger):
        main(is_error=False)
        mock_logger.check(
            (
                'src.main',
                'DEBUG',
                'Hello World.'
            ),
            (
                'src.main',
                'INFO',
                'Function called.'
            )
        )

        # 一旦クリア
        mock_logger.clear()

        main(is_error=True)
        mock_logger.check(
            (
                'src.main',
                'DEBUG',
                'Hello World.'
            ),
            (
                'src.main',
                'INFO',
                'Function called.'
            ),
            (
                'src.main',
                'ERROR',
                'Error occurred.'
            )
        )

LogCaptureの有効化/無効化

...省略
    def test_logging_2(self, mock_logger):
        # 無効化
        mock_logger.uninstall()
        main(is_error=False)
        mock_logger.check()

        # 有効化
        mock_logger.install()
        main(is_error=False)
        mock_logger.check(
            (
                'src.main',
                'DEBUG',
                'Hello World.'
            ),
            (
                'src.main',
                'INFO',
                'Function called.'
            )
        )

一部のログが含まれるかチェック

...省略
    def test_logging_3(self, mock_logger):
        main(is_error=False)
        mock_logger.check_present(
            (
                'src.main',
                'DEBUG',
                'Hello World.'
            )
        )

順不同を許容してチェック

...省略
    def test_logging_4(self, mock_logger):
        main(is_error=False)
        mock_logger.check_present(
            (
                'src.main',
                'INFO',
                'Function called.'
            ),
            (
                'src.main',
                'DEBUG',
                'Hello World.'
            ),
            order_matters=False
        )

ログレベルを指定してチェック

import pytest
import logging

from testfixtures import LogCapture
from src.main import main


@pytest.fixture(scope='function')
def mock_logger_only_error_level():
    with LogCapture(level=logging.ERROR) as log:
        yield log


class TestClass:
    def test_logging(self, mock_logger_only_error_level):
        main(is_error=True)
        mock_logger_only_error_level.check(
            (
                'src.main',
                'ERROR',
                'Error occurred.'
            )
        )

log_captureデコレータを使っても同じことができる

import pytest
import logging

from testfixtures import log_capture
from src.main import main


class TestClass:
    @log_capture()
    def test_logging(self, capture):
        main(is_error=False)
        capture.check_present(
            (
                'src.main',
                'INFO',
                'Function called.'
            )
        )

まとめ

いかがだったでしょうか。

個人の備忘録として書きましたが、どなたかの役に立てば幸いです。