Refactor log.LogFilter

This essentially does two things:

1) Use a set for LogFilter

This means we don't support filters like "eggs.bacon" anymore (but we *do*
support loggers like that) - however, those were already disallowed by the
--logfilter argument validation anyways!

In return, we get probably slightly better performance (checking set membership
rather than iterating all filters) and more straightforward code.

2) Move parsing from various locations around the code to the LogFilter class.

5 files changed, 193 insertions, 81 deletions

diff --git a/qutebrowser/misc/utilcmds.py b/qutebrowser/misc/utilcmds.py
index 2a4b543f8..05fea9501 100644
--- a/qutebrowser/misc/utilcmds.py
+++ b/qutebrowser/misc/utilcmds.py
@@ -236,16 +236,12 @@ def debug_log_filter(filters: str) -> None:
         raise cmdutils.CommandError("No log.console_filter. Not attached "
                                     "to a console?")
 
-    if filters.strip().lower() == 'none':
-        log.console_filter.names = None
-        return
-
-    if not set(filters.split(',')).issubset(log.LOGGER_NAMES):
-        raise cmdutils.CommandError("filters: Invalid value {} - expected one "
-                                    "of: {}".format(
-                                        filters, ', '.join(log.LOGGER_NAMES)))
+    try:
+        new_filter = log.LogFilter.parse(filters)
+    except log.InvalidLogFilterError as e:
+        raise cmdutils.CommandError(e)
 
-    log.console_filter.names = filters.split(',')
+    log.console_filter.update_from(new_filter)
 
 
 @cmdutils.register()
diff --git a/qutebrowser/qutebrowser.py b/qutebrowser/qutebrowser.py
index 3369c1ebe..8765f5217 100644
--- a/qutebrowser/qutebrowser.py
+++ b/qutebrowser/qutebrowser.py
@@ -150,12 +150,11 @@ def logfilter_error(logfilter):
         logfilter: A comma separated list of logger names.
     """
     from qutebrowser.utils import log
-    if set(logfilter.lstrip('!').split(',')).issubset(log.LOGGER_NAMES):
-        return logfilter
-    else:
-        raise argparse.ArgumentTypeError(
-            "filters: Invalid value {} - expected a list of: {}".format(
-                logfilter, ', '.join(log.LOGGER_NAMES)))
+    try:
+        log.LogFilter.parse(logfilter)
+    except log.InvalidLogFilterError as e:
+        raise argparse.ArgumentTypeError(e)
+    return logfilter
 
 
 def debug_flag_error(flag):
diff --git a/qutebrowser/utils/log.py b/qutebrowser/utils/log.py
index 6f117f1a6..e603ea2b2 100644
--- a/qutebrowser/utils/log.py
+++ b/qutebrowser/utils/log.py
@@ -193,16 +193,7 @@ def init_log(args: argparse.Namespace) -> None:
     root = logging.getLogger()
     global console_filter
     if console is not None:
-        if not args.logfilter:
-            negate = False
-            names = None
-        elif args.logfilter.startswith('!'):
-            negate = True
-            names = args.logfilter[1:].split(',')
-        else:
-            negate = False
-            names = args.logfilter.split(',')
-        console_filter = LogFilter(names, negate)
+        console_filter = LogFilter.parse(args.logfilter)
         console.addFilter(console_filter)
         root.addHandler(console)
     if ram is not None:
@@ -577,6 +568,17 @@ class QtWarningFilter(logging.Filter):
         return do_log
 
 
+class InvalidLogFilterError(Exception):
+
+    """Raised when an invalid filter string is passed to LogFilter.parse()."""
+
+    def __init__(self, names: typing.Set[str]):
+        invalid = names - set(LOGGER_NAMES)
+        super().__init__("Invalid log category {} - valid categories: {}"
+                         .format(', '.join(sorted(invalid)),
+                                 ', '.join(LOGGER_NAMES)))
+
+
 class LogFilter(logging.Filter):
 
     """Filter to filter log records based on the commandline argument.
@@ -585,30 +587,52 @@ class LogFilter(logging.Filter):
     comma-separated list instead.
 
     Attributes:
-        names: A list of record names to filter.
-        negated: Whether names is a list of records to log or to suppress.
+        names: A set of logging names to allow.
+        negated: Whether names is a set of names to log or to suppress.
     """
 
-    def __init__(self, names: typing.Optional[typing.Iterable[str]],
-                 negate: bool = False) -> None:
+    def __init__(self, names: typing.Set[str], negated: bool = False) -> None:
         super().__init__()
         self.names = names
-        self.negated = negate
+        self.negated = negated
+
+    @classmethod
+    def parse(cls, filter_str: typing.Optional[str]) -> 'LogFilter':
+        """Parse a log filter from a string."""
+        if filter_str is None or filter_str == 'none':
+            names = set()
+            negated = False
+        else:
+            filter_str = filter_str.lower()
+
+            if filter_str.startswith('!'):
+                negated = True
+                filter_str = filter_str[1:]
+            else:
+                negated = False
+
+            names = {e.strip() for e in filter_str.split(',')}
+
+        if not names.issubset(LOGGER_NAMES):
+            raise InvalidLogFilterError(names)
+
+        return cls(names=names, negated=negated)
+
+    def update_from(self, other: 'LogFilter') -> None:
+        """Update this filter's properties from another filter."""
+        self.names = other.names
+        self.negated = other.negated
 
     def filter(self, record: logging.LogRecord) -> bool:
         """Determine if the specified record is to be logged."""
-        if self.names is None:
+        if not self.names:
+            # No filter
             return True
-        if record.levelno > logging.DEBUG:
+        elif record.levelno > logging.DEBUG:
             # More important than DEBUG, so we won't filter at all
             return True
-        for name in self.names:
-            if record.name == name:
-                return not self.negated
-            elif not record.name.startswith(name):
-                continue
-            elif record.name[len(name)] == '.':
-                return not self.negated
+        elif record.name.split('.')[0] in self.names:
+            return not self.negated
         return self.negated
 
 
diff --git a/tests/unit/test_qutebrowser.py b/tests/unit/test_qutebrowser.py
new file mode 100644
index 000000000..6dbc24351
--- /dev/null
+++ b/tests/unit/test_qutebrowser.py
@@ -0,0 +1,63 @@
+# vim: ft=python fileencoding=utf-8 sts=4 sw=4 et:
+
+# Copyright 2020 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 qutebrowser.qutebrowser.
+
+(Mainly commandline flag parsing)
+"""
+
+import argparse
+
+import pytest
+
+from qutebrowser import qutebrowser
+
+
+@pytest.fixture
+def parser():
+    return qutebrowser.get_argparser()
+
+
+class TestDebugFlag:
+
+    def test_valid(self, parser):
+        args = parser.parse_args(['--debug-flag', 'chromium', '--debug-flag', 'stack'])
+        assert args.debug_flags == ['chromium', 'stack']
+
+    def test_invalid(self, parser, capsys):
+        with pytest.raises(SystemExit):
+            parser.parse_args(['--debug-flag', 'invalid'])
+
+        _out, err = capsys.readouterr()
+        assert 'Invalid debug flag - valid flags:' in err
+
+
+class TestLogFilter:
+
+    def test_valid(self, parser):
+        args = parser.parse_args(['--logfilter', 'misc'])
+        assert args.logfilter == 'misc'
+
+    def test_invalid(self, parser, capsys):
+        with pytest.raises(SystemExit):
+            parser.parse_args(['--logfilter', 'invalid'])
+
+        _out, err = capsys.readouterr()
+        print(err)
+        assert 'Invalid log category invalid - valid categories' in err
diff --git a/tests/unit/utils/test_log.py b/tests/unit/utils/test_log.py
index bf2af5147..14fa07aeb 100644
--- a/tests/unit/utils/test_log.py
+++ b/tests/unit/utils/test_log.py
@@ -33,6 +33,7 @@ from PyQt5 import QtCore
 from qutebrowser import qutebrowser
 from qutebrowser.utils import log
 from qutebrowser.misc import utilcmds
+from qutebrowser.api import cmdutils
 
 
 @pytest.fixture(autouse=True)
@@ -118,28 +119,23 @@ class TestLogFilter:
 
     @pytest.mark.parametrize('filters, negated, category, logged', [
         # Filter letting all messages through
-        (None, False, 'eggs.bacon.spam', True),
-        (None, False, 'eggs', True),
-        (None, True, 'ham', True),
+        (set(), False, 'eggs.bacon.spam', True),
+        (set(), False, 'eggs', True),
+        (set(), True, 'ham', True),
         # Matching records
-        (['eggs', 'bacon'], False, 'eggs', True),
-        (['eggs', 'bacon'], False, 'bacon', True),
-        (['eggs.bacon'], False, 'eggs.bacon', True),
+        ({'eggs', 'bacon'}, False, 'eggs', True),
+        ({'eggs', 'bacon'}, False, 'bacon', True),
+        ({'eggs'}, False, 'eggs.fried', True),
         # Non-matching records
-        (['eggs', 'bacon'], False, 'spam', False),
-        (['eggs'], False, 'eggsauce', False),
-        (['eggs.bacon'], False, 'eggs.baconstrips', False),
-        # Child loggers
-        (['eggs.bacon', 'spam.ham'], False, 'eggs.bacon.spam', True),
-        (['eggs.bacon', 'spam.ham'], False, 'spam.ham.salami', True),
+        ({'eggs', 'bacon'}, False, 'spam', False),
+        ({'eggs'}, False, 'eggsauce', False),
+        ({'fried'}, False, 'eggs.fried', False),
         # Suppressed records
-        (['eggs', 'bacon'], True, 'eggs', False),
-        (['eggs', 'bacon'], True, 'bacon', False),
-        (['eggs.bacon'], True, 'eggs.bacon', False),
+        ({'eggs', 'bacon'}, True, 'eggs', False),
+        ({'eggs', 'bacon'}, True, 'bacon', False),
         # Non-suppressed records
-        (['eggs', 'bacon'], True, 'spam', True),
-        (['eggs'], True, 'eggsauce', True),
-        (['eggs.bacon'], True, 'eggs.baconstrips', True),
+        ({'eggs', 'bacon'}, True, 'spam', True),
+        ({'eggs'}, True, 'eggsauce', True),
     ])
     def test_logfilter(self, logger, filters, negated, category, logged):
         """Ensure the multi-record filtering filterer filters multiple records.
@@ -150,19 +146,29 @@ class TestLogFilter:
         record = self._make_record(logger, category)
         assert logfilter.filter(record) == logged
 
+    def test_logfilter_benchmark(self, logger, benchmark):
+        record = self._make_record(logger, 'unfiltered')
+        filters = set(log.LOGGER_NAMES)  # Extreme case
+        logfilter = log.LogFilter(filters, negated=False)
+        benchmark(lambda: logfilter.filter(record))
+
     @pytest.mark.parametrize('category', ['eggs', 'bacon'])
     def test_debug(self, logger, category):
         """Test if messages more important than debug are never filtered."""
-        logfilter = log.LogFilter(['eggs'])
+        logfilter = log.LogFilter({'eggs'})
         record = self._make_record(logger, category, level=logging.INFO)
         assert logfilter.filter(record)
 
-    @pytest.mark.parametrize('category, logged_before, logged_after', [
-        ('init', True, False), ('url', False, True), ('js', False, True)])
+    @pytest.mark.parametrize('category, filter_str, logged_before, logged_after', [
+        ('init', 'url,js', True, False),
+        ('url', 'url,js', False, True),
+        ('js', 'url,js', False, True),
+        ('js', 'none', False, True),
+    ])
     def test_debug_log_filter_cmd(self, monkeypatch, logger, category,
-                                  logged_before, logged_after):
+                                  filter_str, logged_before, logged_after):
         """Test the :debug-log-filter command handler."""
-        logfilter = log.LogFilter(["init"])
+        logfilter = log.LogFilter({"init"})
         monkeypatch.setattr(log, 'console_filter', logfilter)
 
         record = self._make_record(logger, category)
@@ -171,6 +177,37 @@ class TestLogFilter:
         utilcmds.debug_log_filter('url,js')
         assert logfilter.filter(record) == logged_after
 
+    def test_debug_log_filter_cmd_invalid(self, monkeypatch):
+        logfilter = log.LogFilter(set())
+        monkeypatch.setattr(log, 'console_filter', logfilter)
+        with pytest.raises(cmdutils.CommandError,
+                           match='Invalid log category blabla'):
+            utilcmds.debug_log_filter('blabla')
+
+    @pytest.mark.parametrize('filter_str, expected_names, negated', [
+        ('!js,misc', {'js', 'misc'}, True),
+        ('js,misc', {'js', 'misc'}, False),
+        ('js, misc', {'js', 'misc'}, False),
+        ('JS, Misc', {'js', 'misc'}, False),
+        (None, set(), False),
+        ('none', set(), False),
+    ])
+    def test_parsing(self, filter_str, expected_names, negated):
+        logfilter = log.LogFilter.parse(filter_str)
+        assert logfilter.names == expected_names
+        assert logfilter.negated == negated
+
+    @pytest.mark.parametrize('filter_str, invalid', [
+        ('js,!misc', '!misc'),
+        ('blabla,js,blablub', 'blabla, blablub'),
+    ])
+    def test_parsing_invalid(self, filter_str, invalid):
+        with pytest.raises(
+                log.InvalidLogFilterError,
+                match='Invalid log category {} - '
+                'valid categories: statusbar, .*'.format(invalid)):
+            log.LogFilter.parse(filter_str)
+
 
 @pytest.mark.parametrize('data, expected', [
     # Less data
@@ -199,7 +236,7 @@ class TestInitLog:
 
     def _get_default_args(self):
         return argparse.Namespace(debug=True, loglevel='debug', color=True,
-                                  loglines=10, logfilter="", force_color=False,
+                                  loglines=10, logfilter=None, force_color=False,
                                   json_logging=False, debug_flags=set())
 
     @pytest.fixture(autouse=True)
@@ -217,9 +254,13 @@ class TestInitLog:
         return self._get_default_args()
 
     @pytest.fixture
-    def empty_args(self):
+    def parser(self):
+        return qutebrowser.get_argparser()
+
+    @pytest.fixture
+    def empty_args(self, parser):
         """Logging commandline arguments without any customization."""
-        return qutebrowser.get_argparser().parse_args([])
+        return parser.parse_args([])
 
     def test_stderr_none(self, args):
         """Test init_log with sys.stderr = None."""
@@ -228,22 +269,6 @@ class TestInitLog:
         log.init_log(args)
         sys.stderr = old_stderr
 
-    @pytest.mark.parametrize('logfilter, expected_names, negated', [
-        ('!one,two', ['one', 'two'], True),
-        ('one,two', ['one', 'two'], False),
-        ('one,!two', ['one', '!two'], False),
-        (None, None, False),
-    ])
-    def test_negation_parser(self, args, mocker,
-                             logfilter, expected_names, negated):
-        """Test parsing the --logfilter argument."""
-        filter_mock = mocker.patch('qutebrowser.utils.log.LogFilter',
-                                   autospec=True)
-        args.logfilter = logfilter
-        log.init_log(args)
-        assert filter_mock.called
-        assert filter_mock.call_args[0] == (expected_names, negated)
-
     def test_python_warnings(self, args, caplog):
         log.init_log(args)
 
@@ -311,6 +336,11 @@ class TestInitLog:
         log.init_from_config(config_stub.val)
         assert log.console_handler.formatter._fmt == log.EXTENDED_FMT
 
+    def test_logfilter(self, parser):
+        args = parser.parse_args(['--logfilter', 'misc'])
+        log.init_log(args)
+        assert log.console_filter.names == {'misc'}
+
 
 class TestHideQtWarning: