extensions: trace the total time of running all uisetup callbacks
Differential Revision: https://phab.mercurial-scm.org/D4510
--- 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:]:
--- 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)
--- 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)