Make tests fail on unexpected logging messages.

tests/browser/http/test_content_disposition.py

@@ -24,7 +24,6 @@ import logging
 import pytest
 
 from qutebrowser.browser import http
-from qutebrowser.utils import log
 
 
 DEFAULT_NAME = 'qutebrowser-download'
@@ -56,7 +55,7 @@ class HeaderChecker:
         """Check if the passed header is ignored."""
         reply = self.stubs.FakeNetworkReply(
             headers={'Content-Disposition': header})
-        with self.caplog.atLevel(logging.ERROR, logger=log.rfc6266.name):
+        with self.caplog.atLevel(logging.ERROR, 'rfc6266'):
             # with self.assertLogs(log.rfc6266, logging.ERROR):
             cd_inline, cd_filename = http.parse_content_disposition(reply)
         assert cd_filename == DEFAULT_NAME

tests/browser/http/test_http_hypothesis.py

@@ -19,6 +19,8 @@
 
 """Hypothesis tests for qutebrowser.browser.http."""
 
+import logging
+
 import pytest
 import hypothesis
 from hypothesis import strategies
@@ -35,10 +37,11 @@ from qutebrowser.browser import http, rfc6266
     'attachment; filename*={}',
 ])
 @hypothesis.given(strategies.text(alphabet=[chr(x) for x in range(255)]))
-def test_parse_content_disposition(template, stubs, s):
+def test_parse_content_disposition(caplog, template, stubs, s):
     """Test parsing headers based on templates which hypothesis completes."""
     header = template.format(s)
     reply = stubs.FakeNetworkReply(headers={'Content-Disposition': header})
+    with caplog.atLevel(logging.ERROR, 'rfc6266'):
         http.parse_content_disposition(reply)
 
 

tests/conftest.py

@@ -23,22 +23,24 @@ import os
 import sys
 import collections
 import itertools
+import logging
 
 import pytest
 
 import stubs as stubsmod
+import logfail
 from qutebrowser.config import configexc
 from qutebrowser.utils import objreg, usertypes
 
 
-@pytest.fixture(scope='session', autouse=True)
-def app_and_logging(qapp):
-    """Initialize a QApplication and logging.
 
-    This ensures that a QApplication is created and used by all tests.
+@pytest.yield_fixture(scope='session', autouse=True)
-    """
+def fail_on_logging():
-    from log import init
+    handler = logfail.LogFailHandler()
-    init()
+    logging.getLogger().addHandler(handler)
+    yield
+    logging.getLogger().removeHandler(handler)
+    handler.close()
 
 
 @pytest.fixture(scope='session')
@@ -58,7 +60,7 @@ def unicode_encode_err():
 
 
 @pytest.fixture(scope='session')
-def qnam():
+def qnam(qapp):
     """Session-wide QNetworkAccessManager."""
     from PyQt5.QtNetwork import QNetworkAccessManager
     nam = QNetworkAccessManager()

tests/keyinput/test_basekeyparser.py

@@ -29,7 +29,6 @@ from PyQt5.QtCore import Qt
 import pytest
 
 from qutebrowser.keyinput import basekeyparser
-from qutebrowser.utils import log
 
 
 CONFIG = {'input': {'timeout': 100}}
@@ -107,7 +106,7 @@ class TestSpecialKeys:
     def setup(self, caplog, fake_keyconfig):
         self.kp = basekeyparser.BaseKeyParser(0)
         self.kp.execute = mock.Mock()
-        with caplog.atLevel(logging.WARNING, log.keyboard.name):
+        with caplog.atLevel(logging.WARNING, 'keyboard'):
             # Ignoring keychain 'ccc' in mode 'test' because keychains are not
             # supported there.
             self.kp.read_config('test')

tests/log.py

@@ -1,68 +0,0 @@
-# vim: ft=python fileencoding=utf-8 sts=4 sw=4 et:
-
-# Copyright 2015 Florian Bruhin (The Compiler) <mail@qutebrowser.org>
-#
-# This file is part of qutebrowser.
-#
-# qutebrowser is free software: you can redistribute it and/or modify
-# it under the terms of the GNU General Public License as published by
-# the Free Software Foundation, either version 3 of the License, or
-# (at your option) any later version.
-#
-# qutebrowser is distributed in the hope that it will be useful,
-# but WITHOUT ANY WARRANTY; without even the implied warranty of
-# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
-# GNU General Public License for more details.
-#
-# You should have received a copy of the GNU General Public License
-# along with qutebrowser.  If not, see <http://www.gnu.org/licenses/>.
-
-"""Logging setup for the tests."""
-
-import logging
-
-from PyQt5.QtCore import (QtDebugMsg, QtWarningMsg, QtCriticalMsg, QtFatalMsg,
-                          qInstallMessageHandler)
-
-
-def init():
-    """Initialize logging for the tests."""
-    logging.basicConfig(format='\nLOG %(levelname)s %(name)s '
-                        '%(module)s:%(funcName)s:%(lineno)d %(message)s',
-                        level=logging.WARNING)
-    logging.captureWarnings(True)
-    qInstallMessageHandler(qt_message_handler)
-
-
-def qt_message_handler(msg_type, context, msg):
-    """Qt message handler to redirect qWarning etc. to the logging system.
-
-    Args:
-        QtMsgType msg_type: The level of the message.
-        QMessageLogContext context: The source code location of the message.
-        msg: The message text.
-    """
-    # Mapping from Qt logging levels to the matching logging module levels.
-    # Note we map critical to ERROR as it's actually "just" an error, and fatal
-    # to critical.
-    qt_to_logging = {
-        QtDebugMsg: logging.DEBUG,
-        QtWarningMsg: logging.WARNING,
-        QtCriticalMsg: logging.ERROR,
-        QtFatalMsg: logging.CRITICAL,
-    }
-    level = qt_to_logging[msg_type]
-    # There's very similar code in utils.log, but we want it duplicated here
-    # for the tests.
-    if context.function is None:
-        func = 'none'
-    else:
-        func = context.function
-    if context.category is None or context.category == 'default':
-        name = 'qt'
-    else:
-        name = 'qt-' + context.category
-    logger = logging.getLogger('qt-tests')
-    record = logger.makeRecord(name, level, context.file, context.line, msg,
-                               None, None, func)
-    logger.handle(record)

tests/logfail.py

@@ -0,0 +1,67 @@
+# vim: ft=python fileencoding=utf-8 sts=4 sw=4 et:
+
+# Copyright 2015 Florian Bruhin (The Compiler) <mail@qutebrowser.org>
+#
+# This file is part of qutebrowser.
+#
+# qutebrowser is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# qutebrowser is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with qutebrowser.  If not, see <http://www.gnu.org/licenses/>.
+
+"""Logging handling for the tests."""
+
+import logging
+
+import pytest
+
+try:
+    import pytest_capturelog
+except ImportError:
+    # When using pytest for pyflakes/pep8/..., the plugin won't be available
+    # but conftest.py will still be loaded.
+    #
+    # However, LogFailHandler.emit will never be used in that case, so we just
+    # ignore the ImportError.
+    pass
+
+
+class LogFailHandler(logging.Handler):
+
+    """A logging handler which makes tests fail on unexpected messages."""
+
+    def __init__(self, level=logging.NOTSET, min_level=logging.WARNING):
+        self._min_level = min_level
+        super().__init__(level)
+
+    def emit(self, record):
+        logger = logging.getLogger(record.name)
+        root_logger = logging.getLogger()
+
+        for h in root_logger.handlers:
+            if isinstance(h, pytest_capturelog.CaptureLogHandler):
+                caplog_handler = h
+                break
+        else:
+            # The CaptureLogHandler is not available anymore during fixture
+            # teardown, so we ignore logging messages emitted there..
+            return
+
+        if (logger.level == record.levelno or
+                caplog_handler.level == record.levelno):
+            # caplog.atLevel(...) was used with the level of this message, i.e.
+            # it was expected.
+            return
+        if record.levelno < self._min_level:
+            return
+        pytest.fail("Got logging message on logger {} with level {}: "
+                    "{}!".format(record.name, record.levelname,
+                                 record.getMessage()))

tests/misc/test_editor.py

@@ -234,13 +234,13 @@ class TestErrorMessage:
     def test_proc_error(self, caplog):
         """Test on_proc_error."""
         self.editor.edit("")
-        with caplog.atLevel(logging.ERROR, 'message'):
+        with caplog.atLevel(logging.ERROR):
             self.editor.on_proc_error(QProcess.Crashed)
             assert len(caplog.records()) == 2
 
     def test_proc_return(self, caplog):
         """Test on_proc_finished with a bad exit status."""
         self.editor.edit("")
-        with caplog.atLevel(logging.ERROR, 'message'):
+        with caplog.atLevel(logging.ERROR):
             self.editor.on_proc_closed(1, QProcess.NormalExit)
-            assert len(caplog.records()) == 3
+            assert len(caplog.records()) == 2

tests/misc/test_guiprocess.py

@@ -23,6 +23,7 @@
 
 import sys
 import textwrap
+import logging
 
 import pytest
 from PyQt5.QtCore import QProcess
@@ -117,8 +118,9 @@ def test_cmd_args(fake_proc):
     assert (fake_proc.cmd, fake_proc.args) == (cmd, args)
 
 
-def test_error(qtbot, proc):
+def test_error(qtbot, proc, caplog):
     """Test the process emitting an error."""
+    with caplog.atLevel(logging.ERROR, 'message'):
         with qtbot.waitSignal(proc.error, raising=True):
             proc.start('this_does_not_exist_either', [])
 

tests/test_logfail.py

@@ -0,0 +1,65 @@
+# vim: ft=python fileencoding=utf-8 sts=4 sw=4 et:
+
+# Copyright 2015 Florian Bruhin (The Compiler) <mail@qutebrowser.org>
+#
+# This file is part of qutebrowser.
+#
+# qutebrowser is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# qutebrowser is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with qutebrowser.  If not, see <http://www.gnu.org/licenses/>.
+
+"""Tests for the LogFailHandler test helper."""
+
+
+import logging
+
+import pytest
+
+
+def test_log_debug():
+    logging.debug('foo')
+
+
+def test_log_warning():
+    with pytest.raises(pytest.fail.Exception):
+        logging.warning('foo')
+
+
+def test_log_expected(caplog):
+    with caplog.atLevel(logging.ERROR):
+        logging.error('foo')
+
+
+def test_log_expected_logger(caplog):
+    logger = 'logfail_test_logger'
+    with caplog.atLevel(logging.ERROR, logger):
+        logging.getLogger(logger).error('foo')
+
+
+def test_log_expected_wrong_level(caplog):
+    with pytest.raises(pytest.fail.Exception):
+        with caplog.atLevel(logging.ERROR):
+            logging.critical('foo')
+
+
+def test_log_expected_logger_wrong_level(caplog):
+    logger = 'logfail_test_logger'
+    with pytest.raises(pytest.fail.Exception):
+        with caplog.atLevel(logging.ERROR, logger):
+            logging.getLogger(logger).critical('foo')
+
+
+def test_log_expected_wrong_logger(caplog):
+    logger = 'logfail_test_logger'
+    with pytest.raises(pytest.fail.Exception):
+        with caplog.atLevel(logging.ERROR, logger):
+            logging.error('foo')

tests/utils/debug/test_log_time.py

@@ -30,7 +30,7 @@ def test_log_time(caplog):
     """Test if log_time logs properly."""
     logger_name = 'qt-tests'
 
-    with caplog.atLevel(logging.DEBUG, logger=logger_name):
+    with caplog.atLevel(logging.DEBUG, logger_name):
         with debug.log_time(logging.getLogger(logger_name), action='foobar'):
             time.sleep(0.1)
 

tests/utils/test_log.py

@@ -238,8 +238,8 @@ class TestHideQtWarning:
 
     def test_unfiltered(self, logger, caplog):
         """Test a message which is not filtered."""
-        with log.hide_qt_warning("World", logger='qt-tests'):
+        with log.hide_qt_warning("World", 'qt-tests'):
-            with caplog.atLevel(logging.WARNING, logger='qt-tests'):
+            with caplog.atLevel(logging.WARNING, 'qt-tests'):
                 logger.warning("Hello World")
         assert len(caplog.records()) == 1
         record = caplog.records()[0]
@@ -248,21 +248,21 @@ class TestHideQtWarning:
 
     def test_filtered_exact(self, logger, caplog):
         """Test a message which is filtered (exact match)."""
-        with log.hide_qt_warning("Hello", logger='qt-tests'):
+        with log.hide_qt_warning("Hello", 'qt-tests'):
-            with caplog.atLevel(logging.WARNING, logger='qt-tests'):
+            with caplog.atLevel(logging.WARNING, 'qt-tests'):
                 logger.warning("Hello")
         assert not caplog.records()
 
     def test_filtered_start(self, logger, caplog):
         """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", 'qt-tests'):
-            with caplog.atLevel(logging.WARNING, logger='qt-tests'):
+            with caplog.atLevel(logging.WARNING, 'qt-tests'):
                 logger.warning("Hello World")
         assert not caplog.records()
 
     def test_filtered_whitespace(self, logger, caplog):
         """Test a message which is filtered (match with whitespace)."""
-        with log.hide_qt_warning("Hello", logger='qt-tests'):
+        with log.hide_qt_warning("Hello", 'qt-tests'):
-            with caplog.atLevel(logging.WARNING, logger='qt-tests'):
+            with caplog.atLevel(logging.WARNING, 'qt-tests'):
                 logger.warning("  Hello World  ")
         assert not caplog.records()

tests/utils/test_standarddir.py

@@ -271,7 +271,7 @@ class TestInitCacheDirTag:
         monkeypatch.setattr('qutebrowser.utils.standarddir.cache',
                             lambda: str(tmpdir))
         mocker.patch('builtins.open', side_effect=OSError)
-        with caplog.atLevel(logging.ERROR, 'misc'):
+        with caplog.atLevel(logging.ERROR, 'init'):
             standarddir._init_cachedir_tag()
         assert len(caplog.records()) == 1
         assert caplog.records()[0].message == 'Failed to create CACHEDIR.TAG'

tests/utils/test_version.py

@@ -105,11 +105,12 @@ class TestGitStr:
         commit_file_mock.return_value = 'deadbeef'
         assert version._git_str() == 'deadbeef'
 
-    def test_frozen_oserror(self, commit_file_mock, monkeypatch):
+    def test_frozen_oserror(self, caplog, commit_file_mock, monkeypatch):
         """Test with sys.frozen=True and OSError when reading git-commit-id."""
         monkeypatch.setattr(qutebrowser.utils.version.sys, 'frozen', True,
                             raising=False)
         commit_file_mock.side_effect = OSError
+        with caplog.atLevel(logging.ERROR, 'misc'):
             assert version._git_str() is None
 
     @pytest.mark.not_frozen
@@ -130,12 +131,14 @@ class TestGitStr:
         commit_file_mock.return_value = '1b4d1dea'
         assert version._git_str() == '1b4d1dea'
 
-    def test_normal_path_oserror(self, mocker, git_str_subprocess_fake):
+    def test_normal_path_oserror(self, mocker, git_str_subprocess_fake,
+                                 caplog):
         """Test with things raising OSError."""
         m = mocker.patch('qutebrowser.utils.version.os')
         m.path.join.side_effect = OSError
         mocker.patch('qutebrowser.utils.version.utils.read_file',
                      side_effect=OSError)
+        with caplog.atLevel(logging.ERROR, 'misc'):
             assert version._git_str() is None
 
     @pytest.mark.not_frozen

tests/utils/usertypes/test_question.py

@@ -86,6 +86,6 @@ def test_abort_typeerror(question, qtbot, mocker, caplog):
     """Test Question.abort() with .emit() raising a TypeError."""
     signal_mock = mocker.patch('qutebrowser.utils.usertypes.Question.aborted')
     signal_mock.emit.side_effect = TypeError
-    with caplog.atLevel(logging.ERROR):
+    with caplog.atLevel(logging.ERROR, 'misc'):
         question.abort()
     assert caplog.records()[0].message == 'Error while aborting question'