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

mercurial/extensions.py

@@ -175,11 +175,11 b' 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 b' 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 b' 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 b' 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 b' 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 b' 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)

mercurial/hg.py

@@ -175,7 +175,7 b' 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:

tests/test-bad-extension.t

@@ -85,21 +85,21 b' 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 b' 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)

tests/test-extension-timing.t

@@ -46,23 +46,23 b' 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 b' 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