Add more performance logging to completion.

qutebrowser/completion/completer.py

@@ -23,7 +23,7 @@ from PyQt5.QtCore import pyqtSlot, QObject, QTimer
 
 from qutebrowser.config import config
 from qutebrowser.commands import cmdutils, runners
-from qutebrowser.utils import log, utils
+from qutebrowser.utils import log, utils, debug
 from qutebrowser.completion.models import miscmodels
 
 
@@ -227,10 +227,11 @@ class Completer(QObject):
         elif func != self._last_completion_func:
             self._last_completion_func = func
             args = (x for x in before_cursor[1:] if not x.startswith('-'))
-            model = func(*args)
-            log.completion.debug('Starting {} completion'
-                                 .format(func.__name__))
-            completion.set_model(model)
+            with debug.log_time(log.completion,
+                    'Instantiate {} completion'.format(func.__name__)):
+                model = func(*args)
+            with debug.log_time(log.completion, 'Set completion model'):
+                completion.set_model(model)
             completion.set_pattern(pattern)
         else:
             log.completion.debug('Setting pattern {}'.format(pattern))

qutebrowser/completion/completionwidget.py

@@ -28,7 +28,7 @@ from PyQt5.QtCore import pyqtSlot, pyqtSignal, Qt, QItemSelectionModel, QSize
 
 from qutebrowser.config import config, style
 from qutebrowser.completion import completiondelegate
-from qutebrowser.utils import utils, usertypes, objreg
+from qutebrowser.utils import utils, usertypes, objreg, debug, log
 from qutebrowser.commands import cmdexc, cmdutils
 
 
@@ -295,10 +295,11 @@ class CompletionView(QTreeView):
             self.expand(model.index(i, 0))
 
     def set_pattern(self, pattern):
-        self.model().set_pattern(pattern)
-        self._resize_columns()
-        self._maybe_update_geometry()
-        self.show()
+        with debug.log_time(log.completion, 'Set pattern {}'.format(pattern)):
+            self.model().set_pattern(pattern)
+            self._resize_columns()
+            self._maybe_update_geometry()
+            self.show()
 
     def _maybe_update_geometry(self):
         """Emit the update_geometry signal if the config says so."""

qutebrowser/completion/models/listcategory.py

@@ -52,15 +52,14 @@ class ListCategory(QSortFilterProxyModel):
         Args:
             val: The value to set.
         """
-        with debug.log_time(log.completion, 'Setting filter pattern'):
-            self.pattern = val
-            val = re.sub(r' +', r' ', val)  # See #1919
-            val = re.escape(val)
-            val = val.replace(r'\ ', '.*')
-            self.pattern_re = re.compile(val, re.IGNORECASE)
-            self.invalidate()
-            sortcol = 0
-            self.sort(sortcol)
+        self.pattern = val
+        val = re.sub(r' +', r' ', val)  # See #1919
+        val = re.escape(val)
+        val = val.replace(r'\ ', '.*')
+        self.pattern_re = re.compile(val, re.IGNORECASE)
+        self.invalidate()
+        sortcol = 0
+        self.sort(sortcol)
 
     def filterAcceptsRow(self, row, parent):
         """Custom filter implementation.

tests/end2end/features/test_completion_bdd.py

@@ -24,5 +24,5 @@ bdd.scenarios('completion.feature')
 @bdd.then(bdd.parsers.parse("the completion model should be {model}"))
 def check_model(quteproc, model):
     """Make sure the completion model was set to something."""
-    pattern = "Starting {} completion".format(model)
+    pattern = "Starting {} completion *".format(model)
     quteproc.wait_for(message=pattern)