雑記 - クッキーの日記

Output appears in "Captured stderr call" but is unavailable in capsys or capfd · Issue #5997 · pytest-dev/pytest · GitHub

以下のように Pokemon というクラスを実装したとします。Pokemon クラスは types を渡してインスタンス化しますが、types の長さが 1 か 2 でなかったときに WARNING をロギングし、標準エラー出力します。

import logging
logger = logging.getLogger(__name__)
handler = logging.StreamHandler()  # デフォルトの送信先は標準エラー出力
handler.setLevel(logging.WARNING)
logger.addHandler(handler)

class Pokemon:
    def __init__(self, types):
        if len(types) < 1 or len(types) > 2:
            logger.warning('invalid types %s', types)
        self.types = types

実際に標準エラー出力されると思います。

from pokemon import Pokemon
poke = Pokemon(['Grass', 'Fire', 'Water'])

$ python main.py 2> log.txt

invalid types ['Grass', 'Fire', 'Water']

そこで、Pokemon クラスのテストを pytest で記述することにします。ロギングと標準エラー出力をテストしたいので、組込みフィクスチャの caplog と capfd を利用します。WARNING がロギングされること、標準エラー出力されることのテストは以下のようにかけると思います。

from pokemon import Pokemon
import logging

def test_0(caplog, capfd):
    poke = Pokemon(['Grass', 'Fire', 'Water'])

    assert caplog.record_tuples == [
        ('pokemon', logging.WARNING, 'invalid types [\'Grass\', \'Fire\', \'Water\']'),
    ]

    _, err = capfd.readouterr()
    assert err.strip() == 'invalid types [\'Grass\', \'Fire\', \'Water\']'

しかし、このテストは標準エラー出力が空であるということで失敗します。それも不可解なことに、画面上は意図通りの標準エラー出力がキャプチャされているかのようにみえます。

$ pytest
...
        _, err = capfd.readouterr()
>       assert err.strip() == 'invalid types [\'Grass\', \'Fire\', \'Water\']'
E       assert '' == "invalid type...re', 'Water']"
E         - invalid types ['Grass', 'Fire', 'Water']

test_pokemon.py:12: AssertionError
--------------------------------- Captured stderr call ----------------------------------
invalid types ['Grass', 'Fire', 'Water']
----------------------------------- Captured log call -----------------------------------
WARNING  pokemon:pokemon.py:10 invalid types ['Grass', 'Fire', 'Water']
================================ short test summary info ================================
FAILED test_pokemon.py::test_0 - assert '' == "invalid type...re', 'Water']"
=================================== 1 failed in 0.13s ===================================

よくわからないのでデバッグプリントを仕込んだり仕込まなかったりして pytest を -s オプションで実行すると思います。すると今度はテストが成功します。ついでにデバッグプリントを仕込んだ場合は虚空に消えます。

$ pytest -s
...
collected 1 item

test_pokemon.py .

=================================== 1 passed in 0.01s ===================================