Comment vérifier un message de journal lorsque je teste du code Python sous nez ?

Question

J'essaie d'écrire un test unitaire simple qui vérifiera que, sous une certaine condition, une classe de mon application enregistrera une erreur via l'API de journalisation standard. Je n'arrive pas à trouver la façon la plus propre de tester cette situation.

Je sais que nose capture déjà des données de journalisation par le biais de son plugin de journalisation, mais cela semble être conçu comme une aide au rapport et au débogage pour les tests qui échouent.

Je vois deux façons de procéder :

• Mocker le module de journalisation, soit de manière fragmentaire (mymodule.logging = mockloggingmodule), soit à l'aide d'une bibliothèque de mockage appropriée.
• Écrire ou utiliser un plugin nose existant pour capturer la sortie et la vérifier.

Si j'opte pour la première approche, j'aimerais savoir quelle est la manière la plus propre de réinitialiser l'état global à ce qu'il était avant que je ne mocke le module de logging.

J'attends avec impatience vos conseils et astuces sur ce sujet...

Answer 1

La réponse la plus simple

Pytest dispose d'une fixation intégrée appelée caplog . Aucune installation n'est nécessaire.

def test_foo(foo, caplog, expected_msgs):

    foo.bar()

    assert [r.msg for r in caplog.records] == expected_msgs

J'aurais aimé connaître caplog avant de perdre 6 heures.

Attention, cependant - il se réinitialise, vous devez donc effectuer votre action SUT dans le même test où vous faites des assertions sur caplog.

Personnellement, je veux que la sortie de ma console soit propre, donc j'aime cela pour faire taire le log-to-stderr :

from logging import getLogger
from pytest import fixture

@fixture
def logger(caplog):

    logger = getLogger()
    _ = [logger.removeHandler(h) for h in logger.handlers if h != caplog.handler]       # type: ignore
    return logger

@fixture
def foo(logger):

    return Foo(logger=logger)

@fixture
def expected_msgs():

    # return whatever it is you expect from the SUT

def test_foo(foo, caplog, expected_msgs):

    foo.bar()

    assert [r.msg for r in caplog.records] == expected_msgs

Il y a beaucoup de choses à aimer dans les fixtures de pytest si vous en avez assez de l'horrible code de unittest.

Answer 2

Pour faire suite à la réponse de Reef, j'ai pris la liberté de coder un exemple à l'aide de pymox . Il introduit des fonctions d'aide supplémentaires qui facilitent la création de fonctions et de méthodes.

import logging

# Code under test:

class Server(object):
    def __init__(self):
        self._payload_count = 0
    def do_costly_work(self, payload):
        # resource intensive logic elided...
        pass
    def process(self, payload):
        self.do_costly_work(payload)
        self._payload_count += 1
        logging.info("processed payload: %s", payload)
        logging.debug("payloads served: %d", self._payload_count)

# Here are some helper functions
# that are useful if you do a lot
# of pymox-y work.

import mox
import inspect
import contextlib
import unittest

def stub_all(self, *targets):
    for target in targets:
        if inspect.isfunction(target):
            module = inspect.getmodule(target)
            self.StubOutWithMock(module, target.__name__)
        elif inspect.ismethod(target):
            self.StubOutWithMock(target.im_self or target.im_class, target.__name__)
        else:
            raise NotImplementedError("I don't know how to stub %s" % repr(target))
# Monkey-patch Mox class with our helper 'StubAll' method.
# Yucky pymox naming convention observed.
setattr(mox.Mox, 'StubAll', stub_all)

@contextlib.contextmanager
def mocking():
    mocks = mox.Mox()
    try:
        yield mocks
    finally:
        mocks.UnsetStubs() # Important!
    mocks.VerifyAll()

# The test case example:

class ServerTests(unittest.TestCase):
    def test_logging(self):
        s = Server()
        with mocking() as m:
            m.StubAll(s.do_costly_work, logging.info, logging.debug)
            # expectations
            s.do_costly_work(mox.IgnoreArg()) # don't care, we test logging here.
            logging.info("processed payload: %s", 'hello')
            logging.debug("payloads served: %d", 1)
            # verified execution
            m.ReplayAll()
            s.process('hello')

if __name__ == '__main__':
    unittest.main()

Answer 3

Si vous définissez une méthode d'aide comme ceci :

import logging

def capture_logging():
    records = []

    class CaptureHandler(logging.Handler):
        def emit(self, record):
            records.append(record)

        def __enter__(self):
            logging.getLogger().addHandler(self)
            return records

        def __exit__(self, exc_type, exc_val, exc_tb):
            logging.getLogger().removeHandler(self)

    return CaptureHandler()

Vous pouvez alors écrire un code de test comme celui-ci :

    with capture_logging() as log:
        ... # trigger some logger warnings
    assert len(log) == ...
    assert log[0].getMessage() == ...

Answer 4

Vous devriez utiliser le mocking, car un jour vous pourriez vouloir changer votre logger pour un logger de base de données par exemple. Vous ne serez pas content s'il essaie de se connecter à la base de données pendant les nosetests.

La simulation continuera à fonctionner même si la sortie standard est supprimée.

J'ai utilisé pyMox Les talons de l'enfant. N'oubliez pas de désactiver les stubs après le test.

Answer 5

Trouvé une réponse depuis que j'ai posté cet article. Pas mal.