exthelper: add some semi-useful trace logs

It'd be nice to make the trace functions a little better-named in the output,
but I'm not sure how much better we can do without overhead. This at least
lets you see if a single reposetup function is eating all the time or if it's
spread over all of them. I needed this because Google's uber-extension has a
long load time and I wasn't sure where the problem was.

Differential Revision: https://phab.mercurial-scm.org/D6381

mercurial/exthelper.py

@@ -15,9 +15,12 b' from . import ('
     commands,
     error,
     extensions,
+    pycompat,
     registrar,
 )
 
+from hgdemandimport import tracing
+
 class exthelper(object):
     """Helper for modular extension setup
 
@@ -135,7 +138,8 b' class exthelper(object):'
         for cont, funcname, wrapper in self._functionwrappers:
             extensions.wrapfunction(cont, funcname, wrapper)
         for c in self._uicallables:
-            c(ui)
+            with tracing.log(b'finaluisetup: %s', pycompat.sysbytes(repr(c))):
+                c(ui)
 
     def finaluipopulate(self, ui):
         """Method to be used as the extension uipopulate
@@ -175,7 +179,8 b' class exthelper(object):'
                     entry[1].append(opt)
 
         for c in self._extcallables:
-            c(ui)
+            with tracing.log(b'finalextsetup: %s', pycompat.sysbytes(repr(c))):
+                c(ui)
 
     def finalreposetup(self, ui, repo):
         """Method to be used as the extension reposetup
@@ -187,7 +192,8 b' class exthelper(object):'
         - Changes to repo.__class__, repo.dirstate.__class__
         """
         for c in self._repocallables:
-            c(ui, repo)
+            with tracing.log(b'finalreposetup: %s', pycompat.sysbytes(repr(c))):
+                c(ui, repo)
 
     def uisetup(self, call):
         """Decorated function will be executed during uisetup