# HG changeset patch
# User Boris Feld <boris.feld@octobus.net>
# Date 1536265205 14400
# Node ID 1a2bfc4d756a6865e67113ff01fe8d2b8fdd9767
# Parent  a5d6bf6032fb84fe1e7529290d38e05424e69bbd
extensions: trace the total time of running all uisetup callbacks

Differential Revision: https://phab.mercurial-scm.org/D4510

diff -r a5d6bf6032fb -r 1a2bfc4d756a mercurial/extensions.py
--- a/mercurial/extensions.py	Mon Sep 10 19:36:25 2018 -0700
+++ b/mercurial/extensions.py	Thu Sep 06 16:20:05 2018 -0400
@@ -284,13 +284,15 @@
 
     broken = set()
     log('- executing uisetup hooks\n')
-    for name in _order[newindex:]:
-        log('  - running uisetup for %r\n', name)
-        with util.timedcm('uisetup %r', name) as stats:
-            if not _runuisetup(name, ui):
-                log('    - the %r extension uisetup failed\n', name)
-                broken.add(name)
-        log('  > uisetup for %r took %s\n', name, stats)
+    with util.timedcm('all uisetup') as alluisetupstats:
+        for name in _order[newindex:]:
+            log('  - running uisetup for %r\n', name)
+            with util.timedcm('uisetup %r', name) as stats:
+                if not _runuisetup(name, ui):
+                    log('    - the %r extension uisetup failed\n', name)
+                    broken.add(name)
+            log('  > uisetup for %r took %s\n', name, stats)
+    log('> all uisetup took %s\n', alluisetupstats)
 
     log('- executing extsetup hooks\n')
     for name in _order[newindex:]:
diff -r a5d6bf6032fb -r 1a2bfc4d756a tests/test-bad-extension.t
--- a/tests/test-bad-extension.t	Mon Sep 10 19:36:25 2018 -0700
+++ b/tests/test-bad-extension.t	Thu Sep 06 16:20:05 2018 -0400
@@ -111,6 +111,7 @@
   debug.extensions:   > uisetup for 'gpg' took * (glob)
   debug.extensions:   - running uisetup for 'baddocext'
   debug.extensions:   > uisetup for 'baddocext' took * (glob)
+  debug.extensions: > all uisetup took * (glob)
   debug.extensions: - executing extsetup hooks
   debug.extensions:   - running extsetup for 'gpg'
   debug.extensions:   > extsetup for 'gpg' took * (glob)
diff -r a5d6bf6032fb -r 1a2bfc4d756a tests/test-extension-timing.t
--- a/tests/test-extension-timing.t	Mon Sep 10 19:36:25 2018 -0700
+++ b/tests/test-extension-timing.t	Thu Sep 06 16:20:05 2018 -0400
@@ -59,6 +59,7 @@
   uisetup called
   uisetup called [status]
   debug.extensions:   > uisetup for 'foobar' took * (glob)
+  debug.extensions: > all uisetup took * (glob)
   debug.extensions: - executing extsetup hooks
   debug.extensions:   - running extsetup for 'foobar'
   debug.extensions:   > extsetup for 'foobar' took * (glob)
@@ -72,6 +73,7 @@
   debug.extensions: > loaded 0 extensions, total time * (glob)
   debug.extensions: - loading configtable attributes
   debug.extensions: - executing uisetup hooks
+  debug.extensions: > all uisetup took * (glob)
   debug.extensions: - executing extsetup hooks
   debug.extensions: - executing remaining aftercallbacks
   debug.extensions: > remaining aftercallbacks completed in * (glob)