D4511: extensions: trace the total time of running all extsetup callbacks

[lothiraldan (Boris Feld)]

lothiraldan created this revision.
Herald added a subscriber: mercurial-devel.
Herald added a reviewer: hg-reviewers.

REPOSITORY
  rHG Mercurial

REVISION DETAIL
  https://phab.mercurial-scm.org/D4511

AFFECTED FILES
  mercurial/extensions.py
  tests/test-bad-extension.t
  tests/test-extension-timing.t

CHANGE DETAILS

diff --git a/tests/test-extension-timing.t b/tests/test-extension-timing.t
--- a/tests/test-extension-timing.t
+++ b/tests/test-extension-timing.t
@@ -63,6 +63,7 @@
   debug.extensions: - executing extsetup hooks
   debug.extensions:   - running extsetup for 'foobar'
   debug.extensions:   > extsetup for 'foobar' took * (glob)
+  debug.extensions: > all extsetup took * (glob)
   debug.extensions: - executing remaining aftercallbacks
   debug.extensions: > remaining aftercallbacks completed in * (glob)
   debug.extensions: - loading extension registration objects
@@ -75,6 +76,7 @@
   debug.extensions: - executing uisetup hooks
   debug.extensions: > all uisetup took * (glob)
   debug.extensions: - executing extsetup hooks
+  debug.extensions: > all extsetup took * (glob)
   debug.extensions: - executing remaining aftercallbacks
   debug.extensions: > remaining aftercallbacks completed in * (glob)
   debug.extensions: - loading extension registration objects
diff --git a/tests/test-bad-extension.t b/tests/test-bad-extension.t
--- a/tests/test-bad-extension.t
+++ b/tests/test-bad-extension.t
@@ -117,6 +117,7 @@
   debug.extensions:   > extsetup for 'gpg' took * (glob)
   debug.extensions:   - running extsetup for 'baddocext'
   debug.extensions:   > extsetup for 'baddocext' took * (glob)
+  debug.extensions: > all extsetup took * (glob)
   debug.extensions: - executing remaining aftercallbacks
   debug.extensions: > remaining aftercallbacks completed in * (glob)
   debug.extensions: - loading extension registration objects
diff --git a/mercurial/extensions.py b/mercurial/extensions.py
--- a/mercurial/extensions.py
+++ b/mercurial/extensions.py
@@ -295,15 +295,17 @@
     log('> all uisetup took %s\n', alluisetupstats)
 
     log('- executing extsetup hooks\n')
-    for name in _order[newindex:]:
-        if name in broken:
-            continue
-        log('  - running extsetup for %r\n', name)
-        with util.timedcm('extsetup %r', name) as stats:
-            if not _runextsetup(name, ui):
-                log('    - the %r extension extsetup failed\n', name)
-                broken.add(name)
-        log('  > extsetup for %r took %s\n', name, stats)
+    with util.timedcm('all extsetup') as allextetupstats:
+        for name in _order[newindex:]:
+            if name in broken:
+                continue
+            log('  - running extsetup for %r\n', name)
+            with util.timedcm('extsetup %r', name) as stats:
+                if not _runextsetup(name, ui):
+                    log('    - the %r extension extsetup failed\n', name)
+                    broken.add(name)
+            log('  > extsetup for %r took %s\n', name, stats)
+    log('> all extsetup took %s\n', allextetupstats)
 
     for name in broken:
         log('    - disabling broken %r extension\n', name)



To: lothiraldan, #hg-reviewers
Cc: mercurial-devel