programing

코 아래에서 Python 코드를 테스트 할 때 로그 메시지를 어떻게 확인해야합니까?

shortcode 2021. 1. 16. 20:24
반응형

코 아래에서 Python 코드를 테스트 할 때 로그 메시지를 어떻게 확인해야합니까?


특정 조건에서 내 애플리케이션의 클래스가 표준 로깅 API를 통해 오류를 기록하는지 확인하는 간단한 단위 테스트를 작성하려고합니다. 이 상황을 테스트하는 가장 깨끗한 방법이 무엇인지 알 수 없습니다.

nose가 이미 로깅 플러그인을 통해 로깅 출력을 캡처하고 있다는 것을 알고 있지만 이는 실패한 테스트에 대한보고 및 디버깅 지원으로 의도 된 것 같습니다.

이 작업을 수행하는 두 가지 방법은 다음과 같습니다.

  • 단편적인 방법 (mymodule.logging = mockloggingmodule) 또는 적절한 모의 라이브러리를 사용하여 로깅 모듈을 모의합니다.
  • 기존 nose 플러그인을 작성하거나 사용하여 출력을 캡처하고 확인합니다.

이전 접근 방식으로 이동하면 로깅 모듈을 조롱하기 전에 전역 상태를 재설정하는 가장 깨끗한 방법이 무엇인지 알고 싶습니다.

이것에 대한 힌트와 팁을 기대합니다 ...


나는 로거를 모의로 사용했지만이 상황에서 로깅 핸들러를 사용하는 것이 가장 좋다는 것을 알았으므로 jkp에서 제안한 문서를 기반으로 작성했습니다 (현재는 죽었지 만 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': [],
        }

python 3.4부터 표준 unittest 라이브러리는 새로운 테스트 어설 션 컨텍스트 관리자 인 assertLogs. 로부터 문서 :

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'])

다행히도 이것은 여러분이 직접 작성해야하는 것이 아닙니다. testfixtures패키지 본체에서 발생하는 모든 로깅 출력을 캡처하는 콘텍스트 관리자 제공 with문. 여기에서 패키지를 찾을 수 있습니다.

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

로깅 테스트 방법에 대한 문서는 다음과 같습니다.

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


업데이트 : 더 이상 아래 답변이 필요하지 않습니다. 사용 내장 된 파이썬 방법 을 대신!

이 답변은 https://stackoverflow.com/a/1049375/1286628 에서 수행 된 작업을 확장합니다 . 핸들러는 거의 동일합니다 (생성자는를 사용하여 더 관용적입니다 super). 또한 표준 라이브러리와 함께 핸들러를 사용하는 방법에 대한 데모를 추가합니다 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()

그런 다음 다음 unittest.TestCase과 같이 표준 라이브러리에서 핸들러를 사용할 수 있습니다 .

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)

Brandon의 대답 :

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)

참고 : 위의 내용은 nosetest 를 호출 하고 도구의 logCapture 플러그인 출력을 가져 오는 것과 충돌하지 않습니다.


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

조롱을 사용해야합니다. 언젠가 로거를 데이터베이스로 변경하고 싶을 수도 있습니다. 코 테스트 중에 데이터베이스에 연결을 시도하면 만족하지 않을 것입니다.

표준 출력이 억제 되더라도 조롱은 계속 작동합니다.

pyMox 의 스텁 을 사용 했습니다 . 테스트 후 스텁을 설정 해제하는 것을 잊지 마십시오.


Found one answer since I posted this. Not bad.


The ExpectLog class implemented in tornado is a great utility:

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

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


Keying off @Reef's answer, I did tried the code below. It works well for me both for Python 2.7 (if you install mock) and for 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()

If you define a helper method like this:

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

Then you can write test code like this:

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

ReferenceURL : https://stackoverflow.com/questions/899067/how-should-i-verify-a-log-message-when-testing-python-code-under-nose

반응형