cleanup: make all uses of timedcm specify what they're timing
It's not used in the timing itself, but it's valuable for the trace
events we emit.
Differential Revision: https://phab.mercurial-scm.org/D4349
--- a/mercurial/extensions.py Tue Aug 21 17:13:35 2018 -0400
+++ b/mercurial/extensions.py Tue Aug 21 17:15:51 2018 -0400
@@ -177,7 +177,7 @@
return _extensions[shortname]
log(' - loading extension: %r\n', shortname)
_extensions[shortname] = None
- with util.timedcm() as stats:
+ with util.timedcm('load extension %r', shortname) as stats:
mod = _importext(name, path, bind(_reportimporterror, ui))
log(' > %r extension loaded in %s\n', shortname, stats)
@@ -196,7 +196,7 @@
_extensions[shortname] = mod
_order.append(shortname)
log(' - invoking registered callbacks: %r\n', shortname)
- with util.timedcm() as stats:
+ with util.timedcm('callbacks extension %r', shortname) as stats:
for fn in _aftercallbacks.get(shortname, []):
fn(loaded=True)
log(' > callbacks completed in %s\n', stats)
@@ -243,7 +243,7 @@
newindex = len(_order)
log('loading %sextensions\n', 'additional ' if newindex else '')
log('- processing %d entries\n', len(result))
- with util.timedcm() as stats:
+ with util.timedcm('load all extensions') as stats:
for (name, path) in result:
if path:
if path[0:1] == '!':
@@ -286,7 +286,7 @@
log('- executing uisetup hooks\n')
for name in _order[newindex:]:
log(' - running uisetup for %r\n', name)
- with util.timedcm() as stats:
+ with util.timedcm('uisetup %r', name) as stats:
if not _runuisetup(name, ui):
log(' - the %r extension uisetup failed\n', name)
broken.add(name)
@@ -297,7 +297,7 @@
if name in broken:
continue
log(' - running extsetup for %r\n', name)
- with util.timedcm() as stats:
+ with util.timedcm('extsetup %r', name) as stats:
if not _runextsetup(name, ui):
log(' - the %r extension extsetup failed\n', name)
broken.add(name)
@@ -309,7 +309,7 @@
# Call aftercallbacks that were never met.
log('- executing remaining aftercallbacks\n')
- with util.timedcm() as stats:
+ with util.timedcm('aftercallbacks') as stats:
for shortname in _aftercallbacks:
if shortname in _extensions:
continue
@@ -353,7 +353,7 @@
('templatefunc', templatefuncs, 'loadfunction'),
('templatekeyword', templatekw, 'loadkeyword'),
]
- with util.timedcm() as stats:
+ with util.timedcm('load registration objects') as stats:
_loadextra(ui, newindex, extraloaders)
log('> extension registration object loading took %s\n', stats)
log('extension loading complete\n')
--- a/mercurial/util.py Tue Aug 21 17:13:35 2018 -0400
+++ b/mercurial/util.py Tue Aug 21 17:15:51 2018 -0400
@@ -2929,7 +2929,7 @@
'''
def wrapper(*args, **kwargs):
- with timedcm() as time_stats:
+ with timedcm(pycompat.bytestr(func.__name__)) as time_stats:
result = func(*args, **kwargs)
stderr = procutil.stderr
stderr.write('%s%s: %s\n' % (
--- a/tests/test-util.py Tue Aug 21 17:13:35 2018 -0400
+++ b/tests/test-util.py Tue Aug 21 17:15:51 2018 -0400
@@ -78,7 +78,7 @@
def testtimedcmcleanexit(self):
# timestamps 1, 4, elapsed time of 4 - 1 = 3
with mocktimer([1, 3], _start_default):
- with util.timedcm() as stats:
+ with util.timedcm('pass') as stats:
# actual context doesn't matter
pass
@@ -89,8 +89,8 @@
def testtimedcmnested(self):
# timestamps 1, 3, 6, 10, elapsed times of 6 - 3 = 3 and 10 - 1 = 9
with mocktimer([1, 2, 3, 4], _start_default):
- with util.timedcm() as outer_stats:
- with util.timedcm() as inner_stats:
+ with util.timedcm('outer') as outer_stats:
+ with util.timedcm('inner') as inner_stats:
# actual context doesn't matter
pass
@@ -106,7 +106,7 @@
# timestamps 1, 4, elapsed time of 4 - 1 = 3
with mocktimer([1, 3], _start_default):
try:
- with util.timedcm() as stats:
+ with util.timedcm('exceptional') as stats:
raise ValueError()
except ValueError:
pass