progress: avoid ui.configbool() lookup when progress bar is active draft default tip
authorGregory Szorc <gregory.szorc@gmail.com>
Tue, 11 Dec 2018 20:31:36 -0800
changeset 53702 2f98b5143437bd319eadcef427caf1c73afd2e91
parent 53700 76d8b20139a3b8b5835c7262216b97275845b582
push id1083
push usergszorc@mozilla.com
push dateWed, 12 Dec 2018 04:35:34 +0000
bugs641942, 580000, 210000, 370000, 948626, 950000, 0
progress: avoid ui.configbool() lookup when progress bar is active Profiling revealed that the ui.configbool('progress', 'debug') during progress bar updates was consuming a significant amount of overhead. This commit adds an attribute on progress bar instances that caches this config option. The impact on `hg perfprogress` with default options is significant: before: ! wall 4.641942 comb 4.580000 user 4.210000 sys 0.370000 (best of 3) after: ! wall 1.948626 comb 1.950000 user 1.950000 sys 0.000000 (best of 5) After this change, profiling reveals that progress.progbar.progress() is now consuming ~73% of time. This change does not improve the execution time if the progress bar is disabled. We may want a more comprehensive solution for that case, as the progress bar won't be enabled in a number of scenarios (e.g. servers and processes not attached to an interactive TTY). I also think that overhead of ~2.0s for 1M updates is a bit high. I suspect further refactoring of the progress bar can significantly reduce overhead. I don't have plans to do this, however. Differential Revision: https://phab.mercurial-scm.org/D5408
mercurial/progress.py
mercurial/ui.py
--- a/mercurial/progress.py
+++ b/mercurial/progress.py
@@ -99,16 +99,18 @@ class progbar(object):
         self.refresh = float(self.ui.config(
             'progress', 'refresh'))
         self.changedelay = max(3 * self.refresh,
                                float(self.ui.config(
                                    'progress', 'changedelay')))
         self.order = self.ui.configlist('progress', 'format')
         self.estimateinterval = self.ui.configwith(
             float, 'progress', 'estimateinterval')
+        # developer config: progress.debug
+        self.debug = self.ui.configbool('progress', 'debug')
 
     def show(self, now, topic, pos, item, unit, total):
         if not shouldprint(self.ui):
             return
         termwidth = self.width()
         self.printed = True
         head = ''
         needprogress = False
--- a/mercurial/ui.py
+++ b/mercurial/ui.py
@@ -1688,16 +1688,24 @@ class ui(object):
             # TODO: consider porting some useful information (e.g. estimated
             # time) from progbar. we might want to support update delay to
             # reduce the cost of transferring progress messages.
             self._fmsgerr.write(None, type=b'progress', topic=topic, pos=pos,
                                 item=item, unit=unit, total=total)
         elif self._progbar is not None:
             self._progbar.progress(topic, pos, item=item, unit=unit,
                                    total=total)
+
+            # Looking up progress.debug in tight loops is expensive. The value
+            # is cached on the progbar object and we can avoid the lookup in
+            # the common case where a progbar is active.
+            if pos is None or not self._progbar.debug:
+                return
+
+        # Keep this logic in sync with above.
         if pos is None or not self.configbool('progress', 'debug'):
             return
 
         if unit:
             unit = ' ' + unit
         if item:
             item = ' ' + item