Как проверить сообщение журнала при тестировании кода Python под носом?

Ответ 1

Раньше я издевался над регистраторами, но в этой ситуации я нашел, что лучше всего использовать обработчики журналирования, поэтому я написал этот на основе документа, предложенного 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': [],
        }

Ответ 2

Начиная с версии python 3.4, стандартная библиотека unittest предлагает новый менеджер контекста утверждения, assertLogs. Из 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'])

Ответ 3

К счастью, это не то, что вы должны написать себе; пакет testfixtures предоставляет менеджер контекста, который фиксирует весь вывод журнала, который встречается в теле оператора with. Пакет можно найти здесь:

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

И вот его документы о том, как проверить ведение журнала:

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

Ответ 4

ОБНОВЛЕНИЕ: больше нет необходимости в ответе ниже. Вместо этого используйте встроенный способ Python !

Этот ответ расширяет работу, выполненную по адресу /questions/166895/how-should-i-verify-a-log-message-when-testing-python-code-under-nose/950145#950145. Обработчик во многом одинаков (конструктор более идиоматичен, использует super). Далее я добавлю демонстрацию того, как использовать обработчик со стандартной библиотечной unittest.

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

    Messages are available from an instance ''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 ''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()

Затем вы можете использовать обработчик в стандартной библиотеке unittest.TestCase следующим образом:

import unittest
import logging
import foo

class TestFoo(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        super(TestFoo, cls).setUpClass()
        # Assuming you follow Python logging module documentation's
        # recommendation about naming your module 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)

Ответ 5

Ответ Брэндона:

pip install testfixtures

сниппет:

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)

Примечание: вышеупомянутое не конфликтует с вызовом nosetests и получением вывода плагина logCapture инструмента

Ответ 6

В ответ на ответ Reef я взял на себя право кодировать пример, используя pymox. Он вводит некоторые дополнительные вспомогательные функции, которые упрощают функции и методы заглушки.

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

Ответ 7

Вы должны использовать насмешку, так как когда-нибудь вы, возможно, захотите изменить свой логгер на, скажем, базу данных. Вы не будете счастливы, если попытаетесь подключиться к базе данных во время nosetests.

Mocking будет продолжать работать, даже если стандартный вывод будет подавлен.

Я использовал pyMox заглушки. Не забудьте отключить заглушки после теста.

Ответ 8

Нашел один ответ, так как я разместил это. Неплохо.

Ответ 9

Класс ExpectLog, реализованный в торнадо, является большой полезностью:

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

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

Ответ 10

Отправляя ответ @Reef, я пробовал код ниже. Он отлично работает для меня как для Python 2.7 (если вы установите mock) и для 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()

Ответ 11

Если вы определите вспомогательный метод следующим образом:

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

Затем вы можете написать тестовый код следующим образом:

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