extensions: trace the total time of running all extsetup callbacks
Differential Revision: https://phab.mercurial-scm.org/D4511
--- a/mercurial/extensions.py Thu Sep 06 16:20:05 2018 -0400
+++ b/mercurial/extensions.py Thu Sep 06 16:21:42 2018 -0400
@@ -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)
--- a/tests/test-bad-extension.t Thu Sep 06 16:20:05 2018 -0400
+++ b/tests/test-bad-extension.t Thu Sep 06 16:21:42 2018 -0400
@@ -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
--- a/tests/test-extension-timing.t Thu Sep 06 16:20:05 2018 -0400
+++ b/tests/test-extension-timing.t Thu Sep 06 16:21:42 2018 -0400
@@ -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