| hg-reviewers |
It's not used in the timing itself, but it's valuable for the trace
events we emit.
| Automatic diff as part of commit; lint not applicable. |
| Automatic diff as part of commit; unit tests not applicable. |
| Path | Packages | |||
|---|---|---|---|---|
| M | mercurial/extensions.py (14 lines) | |||
| M | mercurial/util.py (2 lines) | |||
| M | tests/test-util.py (8 lines) |
| else: | else: | ||||
| shortname = name | shortname = name | ||||
| if shortname in _builtin: | if shortname in _builtin: | ||||
| return None | return None | ||||
| if shortname in _extensions: | if shortname in _extensions: | ||||
| return _extensions[shortname] | return _extensions[shortname] | ||||
| log(' - loading extension: %r\n', shortname) | log(' - loading extension: %r\n', shortname) | ||||
| _extensions[shortname] = None | _extensions[shortname] = None | ||||
| with util.timedcm() as stats: | with util.timedcm('load extension %r', shortname) as stats: | ||||
| mod = _importext(name, path, bind(_reportimporterror, ui)) | mod = _importext(name, path, bind(_reportimporterror, ui)) | ||||
| log(' > %r extension loaded in %s\n', shortname, stats) | log(' > %r extension loaded in %s\n', shortname, stats) | ||||
| # Before we do anything with the extension, check against minimum stated | # Before we do anything with the extension, check against minimum stated | ||||
| # compatibility. This gives extension authors a mechanism to have their | # compatibility. This gives extension authors a mechanism to have their | ||||
| # extensions short circuit when loaded with a known incompatible version | # extensions short circuit when loaded with a known incompatible version | ||||
| # of Mercurial. | # of Mercurial. | ||||
| minver = getattr(mod, 'minimumhgversion', None) | minver = getattr(mod, 'minimumhgversion', None) | ||||
| if minver and util.versiontuple(minver, 2) > util.versiontuple(n=2): | if minver and util.versiontuple(minver, 2) > util.versiontuple(n=2): | ||||
| ui.warn(_('(third party extension %s requires version %s or newer ' | ui.warn(_('(third party extension %s requires version %s or newer ' | ||||
| 'of Mercurial; disabling)\n') % (shortname, minver)) | 'of Mercurial; disabling)\n') % (shortname, minver)) | ||||
| return | return | ||||
| log(' - validating extension tables: %r\n', shortname) | log(' - validating extension tables: %r\n', shortname) | ||||
| _validatetables(ui, mod) | _validatetables(ui, mod) | ||||
| _extensions[shortname] = mod | _extensions[shortname] = mod | ||||
| _order.append(shortname) | _order.append(shortname) | ||||
| log(' - invoking registered callbacks: %r\n', 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, []): | for fn in _aftercallbacks.get(shortname, []): | ||||
| fn(loaded=True) | fn(loaded=True) | ||||
| log(' > callbacks completed in %s\n', stats) | log(' > callbacks completed in %s\n', stats) | ||||
| return mod | return mod | ||||
| def _runuisetup(name, ui): | def _runuisetup(name, ui): | ||||
| uisetup = getattr(_extensions[name], 'uisetup', None) | uisetup = getattr(_extensions[name], 'uisetup', None) | ||||
| if uisetup: | if uisetup: | ||||
| else: | else: | ||||
| log = lambda *a, **kw: None | log = lambda *a, **kw: None | ||||
| result = ui.configitems("extensions") | result = ui.configitems("extensions") | ||||
| if whitelist is not None: | if whitelist is not None: | ||||
| result = [(k, v) for (k, v) in result if k in whitelist] | result = [(k, v) for (k, v) in result if k in whitelist] | ||||
| newindex = len(_order) | newindex = len(_order) | ||||
| log('loading %sextensions\n', 'additional ' if newindex else '') | log('loading %sextensions\n', 'additional ' if newindex else '') | ||||
| log('- processing %d entries\n', len(result)) | 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: | for (name, path) in result: | ||||
| if path: | if path: | ||||
| if path[0:1] == '!': | if path[0:1] == '!': | ||||
| if name not in _disabledextensions: | if name not in _disabledextensions: | ||||
| log(' - skipping disabled extension: %r\n', name) | log(' - skipping disabled extension: %r\n', name) | ||||
| _disabledextensions[name] = path[1:] | _disabledextensions[name] = path[1:] | ||||
| continue | continue | ||||
| try: | try: | ||||
| log('- loading configtable attributes\n') | log('- loading configtable attributes\n') | ||||
| _loadextra(ui, newindex, earlyextraloaders) | _loadextra(ui, newindex, earlyextraloaders) | ||||
| broken = set() | broken = set() | ||||
| log('- executing uisetup hooks\n') | log('- executing uisetup hooks\n') | ||||
| for name in _order[newindex:]: | for name in _order[newindex:]: | ||||
| log(' - running uisetup for %r\n', name) | 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): | if not _runuisetup(name, ui): | ||||
| log(' - the %r extension uisetup failed\n', name) | log(' - the %r extension uisetup failed\n', name) | ||||
| broken.add(name) | broken.add(name) | ||||
| log(' > uisetup for %r took %s\n', name, stats) | log(' > uisetup for %r took %s\n', name, stats) | ||||
| log('- executing extsetup hooks\n') | log('- executing extsetup hooks\n') | ||||
| for name in _order[newindex:]: | for name in _order[newindex:]: | ||||
| if name in broken: | if name in broken: | ||||
| continue | continue | ||||
| log(' - running extsetup for %r\n', name) | 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): | if not _runextsetup(name, ui): | ||||
| log(' - the %r extension extsetup failed\n', name) | log(' - the %r extension extsetup failed\n', name) | ||||
| broken.add(name) | broken.add(name) | ||||
| log(' > extsetup for %r took %s\n', name, stats) | log(' > extsetup for %r took %s\n', name, stats) | ||||
| for name in broken: | for name in broken: | ||||
| log(' - disabling broken %r extension\n', name) | log(' - disabling broken %r extension\n', name) | ||||
| _extensions[name] = None | _extensions[name] = None | ||||
| # Call aftercallbacks that were never met. | # Call aftercallbacks that were never met. | ||||
| log('- executing remaining aftercallbacks\n') | log('- executing remaining aftercallbacks\n') | ||||
| with util.timedcm() as stats: | with util.timedcm('aftercallbacks') as stats: | ||||
| for shortname in _aftercallbacks: | for shortname in _aftercallbacks: | ||||
| if shortname in _extensions: | if shortname in _extensions: | ||||
| continue | continue | ||||
| for fn in _aftercallbacks[shortname]: | for fn in _aftercallbacks[shortname]: | ||||
| log(' - extension %r not loaded, notify callbacks\n', | log(' - extension %r not loaded, notify callbacks\n', | ||||
| shortname) | shortname) | ||||
| fn(loaded=False) | fn(loaded=False) | ||||
| ('colortable', color, 'loadcolortable'), | ('colortable', color, 'loadcolortable'), | ||||
| ('filesetpredicate', fileset, 'loadpredicate'), | ('filesetpredicate', fileset, 'loadpredicate'), | ||||
| ('internalmerge', filemerge, 'loadinternalmerge'), | ('internalmerge', filemerge, 'loadinternalmerge'), | ||||
| ('revsetpredicate', revset, 'loadpredicate'), | ('revsetpredicate', revset, 'loadpredicate'), | ||||
| ('templatefilter', templatefilters, 'loadfilter'), | ('templatefilter', templatefilters, 'loadfilter'), | ||||
| ('templatefunc', templatefuncs, 'loadfunction'), | ('templatefunc', templatefuncs, 'loadfunction'), | ||||
| ('templatekeyword', templatekw, 'loadkeyword'), | ('templatekeyword', templatekw, 'loadkeyword'), | ||||
| ] | ] | ||||
| with util.timedcm() as stats: | with util.timedcm('load registration objects') as stats: | ||||
| _loadextra(ui, newindex, extraloaders) | _loadextra(ui, newindex, extraloaders) | ||||
| log('> extension registration object loading took %s\n', stats) | log('> extension registration object loading took %s\n', stats) | ||||
| log('extension loading complete\n') | log('extension loading complete\n') | ||||
| def _loadextra(ui, newindex, extraloaders): | def _loadextra(ui, newindex, extraloaders): | ||||
| for name in _order[newindex:]: | for name in _order[newindex:]: | ||||
| module = _extensions[name] | module = _extensions[name] | ||||
| if not module: | if not module: | ||||
| the cost of a function, e.g. as follows: | the cost of a function, e.g. as follows: | ||||
| @util.timed | @util.timed | ||||
| def foo(a, b, c): | def foo(a, b, c): | ||||
| pass | pass | ||||
| ''' | ''' | ||||
| def wrapper(*args, **kwargs): | def wrapper(*args, **kwargs): | ||||
| with timedcm() as time_stats: | with timedcm(pycompat.bytestr(func.__name__)) as time_stats: | ||||
| result = func(*args, **kwargs) | result = func(*args, **kwargs) | ||||
| stderr = procutil.stderr | stderr = procutil.stderr | ||||
| stderr.write('%s%s: %s\n' % ( | stderr.write('%s%s: %s\n' % ( | ||||
| ' ' * time_stats.level * 2, pycompat.bytestr(func.__name__), | ' ' * time_stats.level * 2, pycompat.bytestr(func.__name__), | ||||
| time_stats)) | time_stats)) | ||||
| return result | return result | ||||
| return wrapper | return wrapper | ||||
| self.assertEqual(bytes(stats), b'<unknown>') | self.assertEqual(bytes(stats), b'<unknown>') | ||||
| stats.elapsed = 12.34 | stats.elapsed = 12.34 | ||||
| self.assertEqual(str(stats), pycompat.sysstr(util.timecount(12.34))) | self.assertEqual(str(stats), pycompat.sysstr(util.timecount(12.34))) | ||||
| self.assertEqual(bytes(stats), util.timecount(12.34)) | self.assertEqual(bytes(stats), util.timecount(12.34)) | ||||
| def testtimedcmcleanexit(self): | def testtimedcmcleanexit(self): | ||||
| # timestamps 1, 4, elapsed time of 4 - 1 = 3 | # timestamps 1, 4, elapsed time of 4 - 1 = 3 | ||||
| with mocktimer([1, 3], _start_default): | with mocktimer([1, 3], _start_default): | ||||
| with util.timedcm() as stats: | with util.timedcm('pass') as stats: | ||||
| # actual context doesn't matter | # actual context doesn't matter | ||||
| pass | pass | ||||
| self.assertEqual(stats.start, 1) | self.assertEqual(stats.start, 1) | ||||
| self.assertEqual(stats.elapsed, 3) | self.assertEqual(stats.elapsed, 3) | ||||
| self.assertEqual(stats.level, 1) | self.assertEqual(stats.level, 1) | ||||
| def testtimedcmnested(self): | def testtimedcmnested(self): | ||||
| # timestamps 1, 3, 6, 10, elapsed times of 6 - 3 = 3 and 10 - 1 = 9 | # timestamps 1, 3, 6, 10, elapsed times of 6 - 3 = 3 and 10 - 1 = 9 | ||||
| with mocktimer([1, 2, 3, 4], _start_default): | with mocktimer([1, 2, 3, 4], _start_default): | ||||
| with util.timedcm() as outer_stats: | with util.timedcm('outer') as outer_stats: | ||||
| with util.timedcm() as inner_stats: | with util.timedcm('inner') as inner_stats: | ||||
| # actual context doesn't matter | # actual context doesn't matter | ||||
| pass | pass | ||||
| self.assertEqual(outer_stats.start, 1) | self.assertEqual(outer_stats.start, 1) | ||||
| self.assertEqual(outer_stats.elapsed, 9) | self.assertEqual(outer_stats.elapsed, 9) | ||||
| self.assertEqual(outer_stats.level, 1) | self.assertEqual(outer_stats.level, 1) | ||||
| self.assertEqual(inner_stats.start, 3) | self.assertEqual(inner_stats.start, 3) | ||||
| self.assertEqual(inner_stats.elapsed, 3) | self.assertEqual(inner_stats.elapsed, 3) | ||||
| self.assertEqual(inner_stats.level, 2) | self.assertEqual(inner_stats.level, 2) | ||||
| def testtimedcmexception(self): | def testtimedcmexception(self): | ||||
| # timestamps 1, 4, elapsed time of 4 - 1 = 3 | # timestamps 1, 4, elapsed time of 4 - 1 = 3 | ||||
| with mocktimer([1, 3], _start_default): | with mocktimer([1, 3], _start_default): | ||||
| try: | try: | ||||
| with util.timedcm() as stats: | with util.timedcm('exceptional') as stats: | ||||
| raise ValueError() | raise ValueError() | ||||
| except ValueError: | except ValueError: | ||||
| pass | pass | ||||
| self.assertEqual(stats.start, 1) | self.assertEqual(stats.start, 1) | ||||
| self.assertEqual(stats.elapsed, 3) | self.assertEqual(stats.elapsed, 3) | ||||
| self.assertEqual(stats.level, 1) | self.assertEqual(stats.level, 1) | ||||