diff -r 19178aeb9b43 -r 6f2510b581a0 mercurial/extensions.py --- a/mercurial/extensions.py Sat Dec 15 16:52:04 2018 +0900 +++ b/mercurial/extensions.py Sat Dec 15 16:28:29 2018 +0900 @@ -121,13 +121,12 @@ return mod def _reportimporterror(ui, err, failed, next): - # note: this ui.debug happens before --debug is processed, + # note: this ui.log happens before --debug is processed, # Use --config ui.debug=1 to see them. - if ui.configbool('devel', 'debug.extensions'): - ui.debug('debug.extensions: - could not import %s (%s): trying %s\n' - % (failed, stringutil.forcebytestr(err), next)) - if ui.debugflag: - ui.traceback() + ui.log(b'extension', b' - could not import %s (%s): trying %s\n', + failed, stringutil.forcebytestr(err), next) + if ui.debugflag and ui.configbool('devel', 'debug.extensions'): + ui.traceback() def _rejectunicode(name, xs): if isinstance(xs, (list, set, tuple)): @@ -166,7 +165,7 @@ _rejectunicode(t, o._table) _validatecmdtable(ui, getattr(mod, 'cmdtable', {})) -def load(ui, name, path, log=lambda *a: None, loadingtime=None): +def load(ui, name, path, loadingtime=None): if name.startswith('hgext.') or name.startswith('hgext/'): shortname = name[6:] else: @@ -175,11 +174,11 @@ return None if shortname in _extensions: return _extensions[shortname] - log(' - loading extension: %s\n', shortname) + ui.log(b'extension', b' - loading extension: %s\n', shortname) _extensions[shortname] = None with util.timedcm('load extension %s', shortname) as stats: mod = _importext(name, path, bind(_reportimporterror, ui)) - log(' > %s extension loaded in %s\n', shortname, stats) + ui.log(b'extension', b' > %s extension loaded in %s\n', shortname, stats) if loadingtime is not None: loadingtime[shortname] += stats.elapsed @@ -193,16 +192,17 @@ 'of Mercurial (current: %s); disabling)\n') ui.warn(msg % (shortname, minver, util.version())) return - log(' - validating extension tables: %s\n', shortname) + ui.log(b'extension', b' - validating extension tables: %s\n', shortname) _validatetables(ui, mod) _extensions[shortname] = mod _order.append(shortname) - log(' - invoking registered callbacks: %s\n', shortname) + ui.log(b'extension', b' - invoking registered callbacks: %s\n', + shortname) with util.timedcm('callbacks extension %s', shortname) as stats: for fn in _aftercallbacks.get(shortname, []): fn(loaded=True) - log(' > callbacks completed in %s\n', stats) + ui.log(b'extension', b' > callbacks completed in %s\n', stats) return mod def _runuisetup(name, ui): @@ -235,28 +235,25 @@ return True def loadall(ui, whitelist=None): - if ui.configbool('devel', 'debug.extensions'): - log = lambda msg, *values: ui.debug('debug.extensions: ', - msg % values, label='debug.extensions') - else: - log = lambda *a, **kw: None loadingtime = collections.defaultdict(int) result = ui.configitems("extensions") if whitelist is not None: result = [(k, v) for (k, v) in result if k in whitelist] newindex = len(_order) - log('loading %sextensions\n', 'additional ' if newindex else '') - log('- processing %d entries\n', len(result)) + ui.log(b'extension', b'loading %sextensions\n', + 'additional ' if newindex else '') + ui.log(b'extension', b'- processing %d entries\n', len(result)) with util.timedcm('load all extensions') as stats: for (name, path) in result: if path: if path[0:1] == '!': if name not in _disabledextensions: - log(' - skipping disabled extension: %s\n', name) + ui.log(b'extension', + b' - skipping disabled extension: %s\n', name) _disabledextensions[name] = path[1:] continue try: - load(ui, name, path, log, loadingtime) + load(ui, name, path, loadingtime) except Exception as inst: msg = stringutil.forcebytestr(inst) if path: @@ -269,8 +266,8 @@ ui.warn(_("*** (%s)\n") % inst.hint) ui.traceback() - log('> loaded %d extensions, total time %s\n', - len(_order) - newindex, stats) + ui.log(b'extension', b'> loaded %d extensions, total time %s\n', + len(_order) - newindex, stats) # list of (objname, loadermod, loadername) tuple: # - objname is the name of an object in extension module, # from which extra information is loaded @@ -283,52 +280,55 @@ ('configtable', configitems, 'loadconfigtable'), ] - log('- loading configtable attributes\n') + ui.log(b'extension', b'- loading configtable attributes\n') _loadextra(ui, newindex, earlyextraloaders) broken = set() - log('- executing uisetup hooks\n') + ui.log(b'extension', b'- executing uisetup hooks\n') with util.timedcm('all uisetup') as alluisetupstats: for name in _order[newindex:]: - log(' - running uisetup for %s\n', name) + ui.log(b'extension', b' - running uisetup for %s\n', name) with util.timedcm('uisetup %s', name) as stats: if not _runuisetup(name, ui): - log(' - the %s extension uisetup failed\n', name) + ui.log(b'extension', + b' - the %s extension uisetup failed\n', name) broken.add(name) - log(' > uisetup for %s took %s\n', name, stats) + ui.log(b'extension', b' > uisetup for %s took %s\n', name, stats) loadingtime[name] += stats.elapsed - log('> all uisetup took %s\n', alluisetupstats) + ui.log(b'extension', b'> all uisetup took %s\n', alluisetupstats) - log('- executing extsetup hooks\n') + ui.log(b'extension', b'- executing extsetup hooks\n') with util.timedcm('all extsetup') as allextetupstats: for name in _order[newindex:]: if name in broken: continue - log(' - running extsetup for %s\n', name) + ui.log(b'extension', b' - running extsetup for %s\n', name) with util.timedcm('extsetup %s', name) as stats: if not _runextsetup(name, ui): - log(' - the %s extension extsetup failed\n', name) + ui.log(b'extension', + b' - the %s extension extsetup failed\n', name) broken.add(name) - log(' > extsetup for %s took %s\n', name, stats) + ui.log(b'extension', b' > extsetup for %s took %s\n', name, stats) loadingtime[name] += stats.elapsed - log('> all extsetup took %s\n', allextetupstats) + ui.log(b'extension', b'> all extsetup took %s\n', allextetupstats) for name in broken: - log(' - disabling broken %s extension\n', name) + ui.log(b'extension', b' - disabling broken %s extension\n', name) _extensions[name] = None # Call aftercallbacks that were never met. - log('- executing remaining aftercallbacks\n') + ui.log(b'extension', b'- executing remaining aftercallbacks\n') with util.timedcm('aftercallbacks') as stats: for shortname in _aftercallbacks: if shortname in _extensions: continue for fn in _aftercallbacks[shortname]: - log(' - extension %s not loaded, notify callbacks\n', - shortname) + ui.log(b'extension', + b' - extension %s not loaded, notify callbacks\n', + shortname) fn(loaded=False) - log('> remaining aftercallbacks completed in %s\n', stats) + ui.log(b'extension', b'> remaining aftercallbacks completed in %s\n', stats) # loadall() is called multiple times and lingering _aftercallbacks # entries could result in double execution. See issue4646. @@ -352,7 +352,7 @@ # - loadermod is the module where loader is placed # - loadername is the name of the function, # which takes (ui, extensionname, extraobj) arguments - log('- loading extension registration objects\n') + ui.log(b'extension', b'- loading extension registration objects\n') extraloaders = [ ('cmdtable', commands, 'loadcmdtable'), ('colortable', color, 'loadcolortable'), @@ -365,14 +365,15 @@ ] with util.timedcm('load registration objects') as stats: _loadextra(ui, newindex, extraloaders) - log('> extension registration object loading took %s\n', stats) + ui.log(b'extension', b'> extension registration object loading took %s\n', + stats) # Report per extension loading time (except reposetup) for name in sorted(loadingtime): - extension_msg = '> extension %s take a total of %s to load\n' - log(extension_msg, name, util.timecount(loadingtime[name])) + ui.log(b'extension', b'> extension %s take a total of %s to load\n', + name, util.timecount(loadingtime[name])) - log('extension loading complete\n') + ui.log(b'extension', b'extension loading complete\n') def _loadextra(ui, newindex, extraloaders): for name in _order[newindex:]: