# HG changeset patch # User Augie Fackler # Date 2018-10-12 16:30:47 # Node ID 09a37a5d8f5d3a7e3e954eb954d83ad67a8b519a # Parent 25f1c7bd649d2ae4ef6fd21a39cafaad81418c8f extensions: fix up many many debug logs that use %r This gets us a bunch closer on Python 3, but I'll still have to use a ton of sad globs. A previous version of this patch tried to preserve the %r formatting, but upon review Yuya noted that special characters in extension names is very unlikely, so we can just use %s and not sweat the quoting. Differential Revision: https://phab.mercurial-scm.org/D5002 diff --git a/mercurial/extensions.py b/mercurial/extensions.py --- a/mercurial/extensions.py +++ b/mercurial/extensions.py @@ -175,11 +175,11 @@ def load(ui, name, path, log=lambda *a: return None if shortname in _extensions: return _extensions[shortname] - log(' - loading extension: %r\n', shortname) + log(' - loading extension: %s\n', shortname) _extensions[shortname] = None - with util.timedcm('load extension %r', shortname) as stats: + with util.timedcm('load extension %s', shortname) as stats: mod = _importext(name, path, bind(_reportimporterror, ui)) - log(' > %r extension loaded in %s\n', shortname, stats) + log(' > %s extension loaded in %s\n', shortname, stats) if loadingtime is not None: loadingtime[shortname] += stats.elapsed @@ -192,13 +192,13 @@ def load(ui, name, path, log=lambda *a: ui.warn(_('(third party extension %s requires version %s or newer ' 'of Mercurial; disabling)\n') % (shortname, minver)) return - log(' - validating extension tables: %r\n', shortname) + log(' - validating extension tables: %s\n', shortname) _validatetables(ui, mod) _extensions[shortname] = mod _order.append(shortname) - log(' - invoking registered callbacks: %r\n', shortname) - with util.timedcm('callbacks extension %r', shortname) as stats: + log(' - 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) @@ -251,7 +251,7 @@ def loadall(ui, whitelist=None): if path: if path[0:1] == '!': if name not in _disabledextensions: - log(' - skipping disabled extension: %r\n', name) + log(' - skipping disabled extension: %s\n', name) _disabledextensions[name] = path[1:] continue try: @@ -289,12 +289,12 @@ def loadall(ui, whitelist=None): log('- executing uisetup hooks\n') 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: + log(' - running uisetup for %s\n', name) + with util.timedcm('uisetup %s', name) as stats: if not _runuisetup(name, ui): - log(' - the %r extension uisetup failed\n', name) + log(' - the %s extension uisetup failed\n', name) broken.add(name) - log(' > uisetup for %r took %s\n', name, stats) + log(' > uisetup for %s took %s\n', name, stats) loadingtime[name] += stats.elapsed log('> all uisetup took %s\n', alluisetupstats) @@ -303,17 +303,17 @@ def loadall(ui, whitelist=None): 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: + log(' - running extsetup for %s\n', name) + with util.timedcm('extsetup %s', name) as stats: if not _runextsetup(name, ui): - log(' - the %r extension extsetup failed\n', name) + log(' - the %s extension extsetup failed\n', name) broken.add(name) - log(' > extsetup for %r took %s\n', name, stats) + log(' > extsetup for %s took %s\n', name, stats) loadingtime[name] += stats.elapsed log('> all extsetup took %s\n', allextetupstats) for name in broken: - log(' - disabling broken %r extension\n', name) + log(' - disabling broken %s extension\n', name) _extensions[name] = None # Call aftercallbacks that were never met. @@ -324,7 +324,7 @@ def loadall(ui, whitelist=None): continue for fn in _aftercallbacks[shortname]: - log(' - extension %r not loaded, notify callbacks\n', + log(' - extension %s not loaded, notify callbacks\n', shortname) fn(loaded=False) log('> remaining aftercallbacks completed in %s\n', stats) diff --git a/mercurial/hg.py b/mercurial/hg.py --- a/mercurial/hg.py +++ b/mercurial/hg.py @@ -175,7 +175,7 @@ def _peerorrepo(ui, path, create=False, if hook: with util.timedcm('reposetup %r', name) as stats: hook(ui, obj) - log(' > reposetup for %r took %s\n', name, stats) + log(' > reposetup for %s took %s\n', name, stats) log('> all reposetup took %s\n', allreposetupstats) if not obj.local(): for f in wirepeersetupfuncs: diff --git a/tests/test-bad-extension.t b/tests/test-bad-extension.t --- a/tests/test-bad-extension.t +++ b/tests/test-bad-extension.t @@ -85,21 +85,21 @@ show traceback for ImportError of hgext. > | egrep 'extension..[^p]|^Exception|Traceback|ImportError|not import|ModuleNotFound' debug.extensions: loading extensions debug.extensions: - processing 5 entries - debug.extensions: - loading extension: 'gpg' - debug.extensions: > 'gpg' extension loaded in * (glob) - debug.extensions: - validating extension tables: 'gpg' - debug.extensions: - invoking registered callbacks: 'gpg' + debug.extensions: - loading extension: gpg + debug.extensions: > gpg extension loaded in * (glob) + debug.extensions: - validating extension tables: gpg + debug.extensions: - invoking registered callbacks: gpg debug.extensions: > callbacks completed in * (glob) - debug.extensions: - loading extension: 'badext' + debug.extensions: - loading extension: badext *** failed to import extension badext from $TESTTMP/badext.py: bit bucket overflow Traceback (most recent call last): Exception: bit bucket overflow - debug.extensions: - loading extension: 'baddocext' - debug.extensions: > 'baddocext' extension loaded in * (glob) - debug.extensions: - validating extension tables: 'baddocext' - debug.extensions: - invoking registered callbacks: 'baddocext' + debug.extensions: - loading extension: baddocext + debug.extensions: > baddocext extension loaded in * (glob) + debug.extensions: - validating extension tables: baddocext + debug.extensions: - invoking registered callbacks: baddocext debug.extensions: > callbacks completed in * (glob) - debug.extensions: - loading extension: 'badext2' + debug.extensions: - loading extension: badext2 debug.extensions: - could not import hgext.badext2 (No module named *badext2*): trying hgext3rd.badext2 (glob) Traceback (most recent call last): ImportError: No module named badext2 (no-py3 !) @@ -121,16 +121,16 @@ show traceback for ImportError of hgext. debug.extensions: > loaded 2 extensions, total time * (glob) debug.extensions: - loading configtable attributes debug.extensions: - executing uisetup hooks - debug.extensions: - running uisetup for 'gpg' - debug.extensions: > uisetup for 'gpg' took * (glob) - debug.extensions: - running uisetup for 'baddocext' - debug.extensions: > uisetup for 'baddocext' took * (glob) + debug.extensions: - running uisetup for gpg + 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) - debug.extensions: - running extsetup for 'baddocext' - debug.extensions: > extsetup for 'baddocext' took * (glob) + debug.extensions: - running extsetup for gpg + 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) diff --git a/tests/test-extension-timing.t b/tests/test-extension-timing.t --- a/tests/test-extension-timing.t +++ b/tests/test-extension-timing.t @@ -46,23 +46,23 @@ Test extension setup timings $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1 debug.extensions: loading extensions debug.extensions: - processing 1 entries - debug.extensions: - loading extension: 'foobar' - debug.extensions: > 'foobar' extension loaded in * (glob) - debug.extensions: - validating extension tables: 'foobar' - debug.extensions: - invoking registered callbacks: 'foobar' + debug.extensions: - loading extension: foobar + debug.extensions: > foobar extension loaded in * (glob) + debug.extensions: - validating extension tables: foobar + debug.extensions: - invoking registered callbacks: foobar debug.extensions: > callbacks completed in * (glob) debug.extensions: > loaded 1 extensions, total time * (glob) debug.extensions: - loading configtable attributes debug.extensions: - executing uisetup hooks - debug.extensions: - running uisetup for 'foobar' + debug.extensions: - running uisetup for foobar uisetup called [debug] uisetup called uisetup called [status] - debug.extensions: > uisetup for 'foobar' took * (glob) + 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) + 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) @@ -87,7 +87,7 @@ Test extension setup timings debug.extensions: - running reposetup for foobar reposetup called for a ui == repo.ui - debug.extensions: > reposetup for 'foobar' took * (glob) + debug.extensions: > reposetup for foobar took * (glob) debug.extensions: > all reposetup took * (glob) Foo