Rewrite test_log.py to use pytest.

See #660.
This commit is contained in:
Florian Bruhin 2015-05-08 00:06:55 +02:00
parent 99a4765e75
commit 8398fe3bdd

View File

@ -22,231 +22,241 @@
"""Tests for qutebrowser.utils.log.""" """Tests for qutebrowser.utils.log."""
import logging import logging
import unittest
import argparse import argparse
import itertools
import sys import sys
from unittest import mock
import pytest
from PyQt5.QtCore import qWarning
from qutebrowser.utils import log from qutebrowser.utils import log
from PyQt5.QtCore import qWarning
@pytest.yield_fixture(autouse=True)
class BaseTest(unittest.TestCase): def restore_loggers():
"""Fixture to save/restore the logging state.
"""Base class for logging tests.
Based on CPython's Lib/test/test_logging.py. Based on CPython's Lib/test/test_logging.py.
""" """
logger_dict = logging.getLogger().manager.loggerDict
logging._acquireLock()
try:
saved_handlers = logging._handlers.copy()
saved_handler_list = logging._handlerList[:]
saved_loggers = saved_loggers = logger_dict.copy()
saved_name_to_level = logging._nameToLevel.copy()
saved_level_to_name = logging._levelToName.copy()
logger_states = {}
for name in saved_loggers:
logger_states[name] = getattr(saved_loggers[name], 'disabled',
None)
finally:
logging._releaseLock()
def setUp(self): root_logger = logging.getLogger("")
"""Save the old logging configuration.""" root_handlers = root_logger.handlers[:]
original_logging_level = root_logger.getEffectiveLevel()
yield
while root_logger.handlers:
h = root_logger.handlers[0]
root_logger.removeHandler(h)
h.close()
root_logger.setLevel(original_logging_level)
for h in root_handlers:
root_logger.addHandler(h)
logging._acquireLock()
try:
logging._levelToName.clear()
logging._levelToName.update(saved_level_to_name)
logging._nameToLevel.clear()
logging._nameToLevel.update(saved_name_to_level)
logging._handlers.clear()
logging._handlers.update(saved_handlers)
logging._handlerList[:] = saved_handler_list
logger_dict = logging.getLogger().manager.loggerDict logger_dict = logging.getLogger().manager.loggerDict
logging._acquireLock() logger_dict.clear()
try: logger_dict.update(saved_loggers)
self.saved_handlers = logging._handlers.copy() logger_states = logger_states
self.saved_handler_list = logging._handlerList[:] for name in logger_states:
self.saved_loggers = saved_loggers = logger_dict.copy() if logger_states[name] is not None:
self.saved_name_to_level = logging._nameToLevel.copy() saved_loggers[name].disabled = logger_states[name]
self.saved_level_to_name = logging._levelToName.copy() finally:
self.logger_states = {} logging._releaseLock()
for name in saved_loggers:
self.logger_states[name] = getattr(saved_loggers[name],
'disabled', None)
finally:
logging._releaseLock()
self.root_logger = logging.getLogger("")
self.root_handlers = self.root_logger.handlers[:]
self.original_logging_level = self.root_logger.getEffectiveLevel()
def tearDown(self):
"""Restore the original logging configuration."""
while self.root_logger.handlers:
h = self.root_logger.handlers[0]
self.root_logger.removeHandler(h)
h.close()
self.root_logger.setLevel(self.original_logging_level)
for h in self.root_handlers:
self.root_logger.addHandler(h)
logging._acquireLock()
try:
logging._levelToName.clear()
logging._levelToName.update(self.saved_level_to_name)
logging._nameToLevel.clear()
logging._nameToLevel.update(self.saved_name_to_level)
logging._handlers.clear()
logging._handlers.update(self.saved_handlers)
logging._handlerList[:] = self.saved_handler_list
logger_dict = logging.getLogger().manager.loggerDict
logger_dict.clear()
logger_dict.update(self.saved_loggers)
logger_states = self.logger_states
for name in self.logger_states:
if logger_states[name] is not None:
self.saved_loggers[name].disabled = logger_states[name]
finally:
logging._releaseLock()
class LogFilterTests(unittest.TestCase): @pytest.fixture(scope='session')
def log_counter():
"""Counter for logger fixture to get unique loggers."""
return itertools.count()
"""Tests for LogFilter.
Attributes: @pytest.fixture
logger: The logger we use to create records. def logger(log_counter):
"""Fixture which provides a logger for tests.
Unique throwaway loggers are used to make sure the tests don't influence
each other.
""" """
i = next(log_counter)
return logging.getLogger('qutebrowser-unittest-logger-{}'.format(i))
def setUp(self):
self.logger = logging.getLogger("foo")
def _make_record(self, name, level=logging.DEBUG): class TestLogFilter:
"""Tests for LogFilter."""
def _make_record(self, logger, name, level=logging.DEBUG):
"""Create a bogus logging record with the supplied logger name.""" """Create a bogus logging record with the supplied logger name."""
return self.logger.makeRecord(name, level=level, fn=None, lno=0, return logger.makeRecord(name, level=level, fn=None, lno=0, msg="",
msg="", args=None, exc_info=None) args=None, exc_info=None)
def test_empty(self): def test_empty(self, logger):
"""Test if an empty filter lets all messages through.""" """Test if an empty filter lets all messages through."""
logfilter = log.LogFilter(None) logfilter = log.LogFilter(None)
record = self._make_record("eggs.bacon.spam") record = self._make_record(logger, "eggs.bacon.spam")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("eggs") record = self._make_record(logger, "eggs")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
def test_matching(self): def test_matching(self, logger):
"""Test if a filter lets an exactly matching log record through.""" """Test if a filter lets an exactly matching log record through."""
logfilter = log.LogFilter(["eggs", "bacon"]) logfilter = log.LogFilter(["eggs", "bacon"])
record = self._make_record("eggs") record = self._make_record(logger, "eggs")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("bacon") record = self._make_record(logger, "bacon")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("spam") record = self._make_record(logger, "spam")
self.assertFalse(logfilter.filter(record)) assert not logfilter.filter(record)
logfilter = log.LogFilter(["eggs.bacon"]) logfilter = log.LogFilter(["eggs.bacon"])
record = self._make_record("eggs.bacon") record = self._make_record(logger, "eggs.bacon")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
def test_equal_start(self): def test_equal_start(self, logger):
"""Test if a filter blocks a logger which looks equal but isn't.""" """Test if a filter blocks a logger which looks equal but isn't."""
logfilter = log.LogFilter(["eggs"]) logfilter = log.LogFilter(["eggs"])
record = self._make_record("eggsauce") record = self._make_record(logger, "eggsauce")
self.assertFalse(logfilter.filter(record)) assert not logfilter.filter(record)
logfilter = log.LogFilter("eggs.bacon") logfilter = log.LogFilter("eggs.bacon")
record = self._make_record("eggs.baconstrips") record = self._make_record(logger, "eggs.baconstrips")
self.assertFalse(logfilter.filter(record)) assert not logfilter.filter(record)
def test_child(self): def test_child(self, logger):
"""Test if a filter lets through a logger which is a child.""" """Test if a filter lets through a logger which is a child."""
logfilter = log.LogFilter(["eggs.bacon", "spam.ham"]) logfilter = log.LogFilter(["eggs.bacon", "spam.ham"])
record = self._make_record("eggs.bacon.spam") record = self._make_record(logger, "eggs.bacon.spam")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("spam.ham.salami") record = self._make_record(logger, "spam.ham.salami")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
def test_debug(self): def test_debug(self, logger):
"""Test if messages more important than debug are never filtered.""" """Test if messages more important than debug are never filtered."""
logfilter = log.LogFilter(["eggs"]) logfilter = log.LogFilter(["eggs"])
# First check if the filter works as intended with debug messages # First check if the filter works as intended with debug messages
record = self._make_record("eggs") record = self._make_record(logger, "eggs")
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("bacon") record = self._make_record(logger, "bacon")
self.assertFalse(logfilter.filter(record)) assert not logfilter.filter(record)
# Then check if info is not filtered # Then check if info is not filtered
record = self._make_record("eggs", level=logging.INFO) record = self._make_record(logger, "eggs", level=logging.INFO)
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
record = self._make_record("bacon", level=logging.INFO) record = self._make_record(logger, "bacon", level=logging.INFO)
self.assertTrue(logfilter.filter(record)) assert logfilter.filter(record)
class RAMHandlerTests(BaseTest): class TestRAMHandler:
"""Tests for RAMHandler. """Tests for RAMHandler."""
Attributes: @pytest.fixture
logger: The logger we use to log to the handler. def handler(self, logger):
handler: The RAMHandler we're testing. """Fixture providing a RAMHandler."""
old_level: The level the root logger had before executing the test. handler = log.RAMHandler(capacity=2)
old_handlers: The handlers the root logger had before executing the handler.setLevel(logging.NOTSET)
test. logger.addHandler(handler)
""" return handler
def setUp(self): def test_filled(self, handler, logger):
super().setUp()
self.logger = logging.getLogger()
self.logger.handlers = []
self.logger.setLevel(logging.NOTSET)
self.handler = log.RAMHandler(capacity=2)
self.handler.setLevel(logging.NOTSET)
self.logger.addHandler(self.handler)
def test_filled(self):
"""Test handler with exactly as much records as it can hold.""" """Test handler with exactly as much records as it can hold."""
self.logger.debug("One") logger.debug("One")
self.logger.debug("Two") logger.debug("Two")
self.assertEqual(len(self.handler._data), 2) assert len(handler._data) == 2
self.assertEqual(self.handler._data[0].msg, "One") assert handler._data[0].msg == "One"
self.assertEqual(self.handler._data[1].msg, "Two") assert handler._data[1].msg == "Two"
def test_overflow(self): def test_overflow(self, handler, logger):
"""Test handler with more records as it can hold.""" """Test handler with more records as it can hold."""
self.logger.debug("One") logger.debug("One")
self.logger.debug("Two") logger.debug("Two")
self.logger.debug("Three") logger.debug("Three")
self.assertEqual(len(self.handler._data), 2) assert len(handler._data) == 2
self.assertEqual(self.handler._data[0].msg, "Two") assert handler._data[0].msg == "Two"
self.assertEqual(self.handler._data[1].msg, "Three") assert handler._data[1].msg == "Three"
def test_dump_log(self): def test_dump_log(self, handler, logger):
"""Test dump_log().""" """Test dump_log()."""
self.logger.debug("One") logger.debug("One")
self.logger.debug("Two") logger.debug("Two")
self.logger.debug("Three") logger.debug("Three")
self.assertEqual(self.handler.dump_log(), "Two\nThree") assert handler.dump_log() == "Two\nThree"
@mock.patch('qutebrowser.utils.log.qInstallMessageHandler', autospec=True) class TestInitLog:
class InitLogTests(BaseTest):
"""Tests for init_log.""" """Tests for init_log."""
def setUp(self): @pytest.fixture(autouse=True)
super().setUp() def setup(self, mocker):
self.args = argparse.Namespace(debug=True, loglevel=logging.DEBUG, """Mock out qInstallMessageHandler."""
color=True, loglines=10, logfilter="") mocker.patch('qutebrowser.utils.log.qInstallMessageHandler',
autospec=True)
def test_stderr_none(self, _mock): @pytest.fixture
def args(self):
"""Fixture providing an argparse namespace."""
return argparse.Namespace(debug=True, loglevel=logging.DEBUG,
color=True, loglines=10, logfilter="")
def test_stderr_none(self, args):
"""Test init_log with sys.stderr = None.""" """Test init_log with sys.stderr = None."""
old_stderr = sys.stderr old_stderr = sys.stderr
sys.stderr = None sys.stderr = None
log.init_log(self.args) log.init_log(args)
sys.stderr = old_stderr sys.stderr = old_stderr
class HideQtWarningTests(BaseTest): class TestHideQtWarning:
"""Tests for hide_qt_warning/QtWarningFilter.""" """Tests for hide_qt_warning/QtWarningFilter."""
def test_unfiltered(self): def test_unfiltered(self, caplog):
"""Test a message which is not filtered.""" """Test a message which is not filtered."""
with log.hide_qt_warning("World", logger='qt-tests'): with log.hide_qt_warning("World", logger='qt-tests'):
with self.assertLogs('qt-tests', logging.WARNING): with caplog.atLevel(logging.WARNING, logger='qt-tests'):
qWarning("Hello World") qWarning("Hello World")
assert len(caplog.records()) == 1
record = caplog.records()[0]
assert record.levelname == 'WARNING'
assert record.message == "Hello World"
def test_filtered_exact(self): def test_filtered_exact(self, caplog):
"""Test a message which is filtered (exact match).""" """Test a message which is filtered (exact match)."""
with log.hide_qt_warning("Hello", logger='qt-tests'): with log.hide_qt_warning("Hello", logger='qt-tests'):
qWarning("Hello") with caplog.atLevel(logging.WARNING, logger='qt-tests'):
qWarning("Hello")
assert not caplog.records()
def test_filtered_start(self): def test_filtered_start(self, caplog):
"""Test a message which is filtered (match at line start).""" """Test a message which is filtered (match at line start)."""
with log.hide_qt_warning("Hello", logger='qt-tests'): with log.hide_qt_warning("Hello", logger='qt-tests'):
qWarning("Hello World") with caplog.atLevel(logging.WARNING, logger='qt-tests'):
qWarning("Hello World")
assert not caplog.records()
def test_filtered_whitespace(self): def test_filtered_whitespace(self, caplog):
"""Test a message which is filtered (match with whitespace).""" """Test a message which is filtered (match with whitespace)."""
with log.hide_qt_warning("Hello", logger='qt-tests'): with log.hide_qt_warning("Hello", logger='qt-tests'):
qWarning(" Hello World ") with caplog.atLevel(logging.WARNING, logger='qt-tests'):
qWarning(" Hello World ")
assert not caplog.records()
if __name__ == '__main__':
unittest.main()