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

À partir de la version 3.4 de Python, la norme unittest propose un nouveau gestionnaire de contexte d'assertion de test, assertLogs . De la documents :

with self.assertLogs('foo', level='INFO') as cm:
    logging.getLogger('foo').info('first message')
    logging.getLogger('foo.bar').error('second message')
    self.assertEqual(cm.output, ['INFO:foo:first message',
                                 'ERROR:foo.bar:second message'])

Answer 2

Heureusement, ce n'est pas quelque chose que vous devez écrire vous-même. testfixtures fournit un gestionnaire de contexte qui capture toutes les données de journalisation qui se produisent dans le corps du fichier with déclaration. Vous pouvez trouver le paquet ici :

http://pypi.python.org/pypi/testfixtures

Et voici sa documentation sur la façon de tester la journalisation :

http://testfixtures.readthedocs.org/en/latest/logging.html

Answer 3

MISE À JOUR : La réponse ci-dessous n'est plus nécessaire. Utiliser le façon intégrée Python au lieu de cela !

Cette réponse prolonge le travail effectué dans https://stackoverflow.com/a/1049375/1286628 . Le gestionnaire est en grande partie le même (le constructeur est plus idiomatique, utilisant super ). De plus, j'ajoute une démonstration de l'utilisation du gestionnaire avec la fonction unittest .

class MockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs.

    Messages are available from an instance's ``messages`` dict, in order, indexed by
    a lowercase log level string (e.g., 'debug', 'info', etc.).
    """

    def __init__(self, *args, **kwargs):
        self.messages = {'debug': [], 'info': [], 'warning': [], 'error': [],
                         'critical': []}
        super(MockLoggingHandler, self).__init__(*args, **kwargs)

    def emit(self, record):
        "Store a message from ``record`` in the instance's ``messages`` dict."
        try:
            self.messages[record.levelname.lower()].append(record.getMessage())
        except Exception:
            self.handleError(record)

    def reset(self):
        self.acquire()
        try:
            for message_list in self.messages.values():
                message_list.clear()
        finally:
            self.release()

Vous pouvez ensuite utiliser le gestionnaire dans une bibliothèque standard unittest.TestCase comme suit :

import unittest
import logging
import foo

class TestFoo(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        super(TestFoo, cls).setUpClass()
        # Assuming you follow Python's logging module's documentation's
        # recommendation about naming your module's logs after the module's
        # __name__,the following getLogger call should fetch the same logger
        # you use in the foo module
        foo_log = logging.getLogger(foo.__name__)
        cls._foo_log_handler = MockLoggingHandler(level='DEBUG')
        foo_log.addHandler(cls._foo_log_handler)
        cls.foo_log_messages = cls._foo_log_handler.messages

    def setUp(self):
        super(TestFoo, self).setUp()
        self._foo_log_handler.reset() # So each test is independent

    def test_foo_objects_fromble_nicely(self):
        # Do a bunch of frombling with foo objects
        # Now check that they've logged 5 frombling messages at the INFO level
        self.assertEqual(len(self.foo_log_messages['info']), 5)
        for info_message in self.foo_log_messages['info']:
            self.assertIn('fromble', info_message)

Answer 4

J'avais l'habitude de me moquer des loggers, mais dans cette situation, j'ai trouvé préférable d'utiliser des gestionnaires de logging, et j'ai donc écrit celui-ci en me basant sur le document proposé par jkp (aujourd'hui mort, mais mis en cache sur Internet Archive )

class MockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs."""

    def __init__(self, *args, **kwargs):
        self.reset()
        logging.Handler.__init__(self, *args, **kwargs)

    def emit(self, record):
        self.messages[record.levelname.lower()].append(record.getMessage())

    def reset(self):
        self.messages = {
            'debug': [],
            'info': [],
            'warning': [],
            'error': [],
            'critical': [],
        }

Answer 5

Réponse de Brandon :

pip install testfixtures

extrait :

import logging
from testfixtures import LogCapture
logger = logging.getLogger('')

with LogCapture() as logs:
    # my awesome code
    logger.error('My code logged an error')
assert 'My code logged an error' in str(logs)

Note : ce qui précède n'est pas en contradiction avec le fait d'appeler nosetests et obtenir la sortie du plugin logCapture de l'outil