unit - ¿Cómo debo verificar un mensaje de registro cuando pruebo el código Python debajo de la nariz?

python unittest

Question

Intento escribir una prueba simple de unidad que verificará que, bajo ciertas condiciones, una clase en mi aplicación registrará un error a través de la API de registro estándar. No puedo entender cuál es la forma más limpia de probar esta situación.

Sé que nose ya capta la salida de registro a través de su plugin de registro, pero parece que pretende ser una herramienta de informes y depuración para pruebas fallidas.

Las dos formas de hacer esto que puedo ver son:

• Simula el módulo de registro, ya sea de manera fragmentada (mymodule.logging = mockloggingmodule) o con una biblioteca de burlas apropiada.
• Escriba o use un complemento de nariz existente para capturar la salida y verificarla.

Si tomo el enfoque anterior, me gustaría saber cuál es la forma más limpia de restablecer el estado global a lo que era antes de burlarme del módulo de registro.

Esperamos sus sugerencias y consejos sobre este ...

Answer 1

Afortunadamente, esto no es algo que debes escribir tú mismo; el paquete testfixtures proporciona un administrador de contexto que captura todos los resultados de registro que se producen en el cuerpo de la sentencia with . Puedes encontrar el paquete aquí:

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

Y aquí están sus documentos sobre cómo probar el registro:

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

Answer 2

Como seguimiento a la respuesta de Reef, me tomé la libertad de codificar un ejemplo usando pymox . Introduce algunas funciones auxiliares adicionales que facilitan el corte de funciones y métodos.

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

Debería usar burlas, ya que algún día podría querer cambiar su registrador a, por ejemplo, una base de datos. No te alegrará si intenta conectarse a la base de datos durante las pruebas de nariz.

La burla continuará funcionando incluso si se suprime la salida estándar.

He usado los talones de pyMox . Recuerde desarmar los talones después de la prueba.

Answer 4

Desde Python 3.4 en adelante, la biblioteca estándar de prueba assertLogs ofrece un nuevo administrador de contexto de afirmación de prueba, assertLogs . De los docs :

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 5

Encontré una respuesta desde que publiqué esto. No está mal.

Answer 6

Excluyendo la respuesta de @ Reef, probé el código a continuación. Funciona bien para mí tanto para Python 2.7 (si instala mock ) como para Python 3.4.

"""
Demo using a mock to test logging output.
"""

import logging
try:
    import unittest
except ImportError:
    import unittest2 as unittest

try:
    # Python >= 3.3
    from unittest.mock import Mock, patch
except ImportError:
    from mock import Mock, patch

logging.basicConfig()
LOG=logging.getLogger("(logger under test)")

class TestLoggingOutput(unittest.TestCase):
    """ Demo using Mock to test logging INPUT. That is, it tests what
    parameters were used to invoke the logging method, while still
    allowing actual logger to execute normally.

    """
    def test_logger_log(self):
        """Check for Logger.log call."""
        original_logger = LOG
        patched_log = patch(''__main__.LOG.log'',
                            side_effect=original_logger.log).start()

        log_msg = ''My log msg.''
        level = logging.ERROR
        LOG.log(level, log_msg)

        # call_args is a tuple of positional and kwargs of the last call
        # to the mocked function.
        # Also consider using call_args_list
        # See: https://docs.python.org/3/library/unittest.mock.html#unittest.mock.Mock.call_args
        expected = (level, log_msg)
        self.assertEqual(expected, patched_log.call_args[0])


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

Answer 7

La clase ExpectLog implementada en tornado es una gran utilidad:

with ExpectLog(''channel'', ''message regex''):
    do_it()

http://tornado.readthedocs.org/en/latest/_modules/tornado/testing.html#ExpectLog

Answer 8

La respuesta de Brandon:

pip install testfixtures

retazo:

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)

Nota: lo anterior no entra en conflicto con la invocación de nosetests y obtener el resultado del complemento logCapture de la herramienta

Answer 9

Solía ​​burlarme de los registradores, pero en esta situación, me pareció mejor usar manejadores de registro, así que escribí este basado en el documento sugerido por jkp :

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 10

ACTUALIZACIÓN : Ya no es necesario que respondas a continuación. ¡Utiliza la forma docs.python.org/3/library/… lugar!

Esta respuesta amplía el trabajo realizado en https://.com/a/1049375/1286628 . El controlador es básicamente el mismo (el constructor es más idiomático, usa super ). Además, agrego una demostración de cómo usar el controlador con la prueba unitaria de la biblioteca estándar.

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()

Entonces puede usar el controlador en una unittest.TestCase biblioteca estándar. unittest.TestCase así:

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)