Verbosity: add another "debug2" function for level 3, use it for event debugging. Prefix debug messages with component name.

1 files changed, 39 insertions, 27 deletions

diff --git a/sphinx/application.py b/sphinx/application.py
index d49a0fa2..02f0ff82 100644
--- a/sphinx/application.py
+++ b/sphinx/application.py
@@ -35,7 +35,7 @@ from sphinx.environment import BuildEnvironment, SphinxStandaloneReader
 from sphinx.util import pycompat  # imported for side-effects
 from sphinx.util.tags import Tags
 from sphinx.util.osutil import ENOENT
-from sphinx.util.console import bold
+from sphinx.util.console import bold, lightgray, darkgray
 
 
 # List of all known core events. Maps name to arguments description.
@@ -196,6 +196,8 @@ class Sphinx(object):
         self.builder = builderclass(self)
         self.emit('builder-inited')
 
+    # ---- main "build" method -------------------------------------------------
+
     def build(self, force_all=False, filenames=None):
         try:
             if force_all:
@@ -215,6 +217,8 @@ class Sphinx(object):
             self.emit('build-finished', None)
         self.builder.cleanup()
 
+    # ---- logging handling ----------------------------------------------------
+
     def _log(self, message, wfile, nonl=False):
         try:
             wfile.write(message)
@@ -255,13 +259,20 @@ class Sphinx(object):
             return
         if args or kwargs:
             message = message % (args or kwargs)
-        self._log(message, self._status)
+        self._log(darkgray(message), self._status)
+
+    def debug2(self, message, *args, **kwargs):
+        if self.verbosity < 3:
+            return
+        if args or kwargs:
+            message = message % (args or kwargs)
+        self._log(lightgray(message), self._status)
 
-    # general extensibility interface
+    # ---- general extensibility interface -------------------------------------
 
     def setup_extension(self, extension):
         """Import and setup a Sphinx extension module. No-op if called twice."""
-        self.debug('setting up extension: %r', extension)
+        self.debug('[app] setting up extension: %r', extension)
         if extension in self._extensions:
             return
         try:
@@ -322,16 +333,17 @@ class Sphinx(object):
         else:
             self._listeners[event][listener_id] = callback
         self.next_listener_id += 1
-        self.debug('connecting event %r: %r [id=%s]',
+        self.debug('[app] connecting event %r: %r [id=%s]',
                    event, callback, listener_id)
         return listener_id
 
     def disconnect(self, listener_id):
-        self.debug('disconnecting event: [id=%s]', listener_id)
+        self.debug('[app] disconnecting event: [id=%s]', listener_id)
         for event in self._listeners.itervalues():
             event.pop(listener_id, None)
 
     def emit(self, event, *args):
+        self.debug2('[app] emitting event: %r%s', event, str(args)[:100])
         results = []
         if event in self._listeners:
             for _, callback in self._listeners[event].iteritems():
@@ -347,7 +359,7 @@ class Sphinx(object):
     # registering addon parts
 
     def add_builder(self, builder):
-        self.debug('adding builder: %r', builder)
+        self.debug('[app] adding builder: %r', builder)
         if not hasattr(builder, 'name'):
             raise ExtensionError('Builder class %s has no "name" attribute'
                                  % builder)
@@ -362,7 +374,7 @@ class Sphinx(object):
         self.builderclasses[builder.name] = builder
 
     def add_config_value(self, name, default, rebuild):
-        self.debug('adding config value: %r', (name, default, rebuild))
+        self.debug('[app] adding config value: %r', (name, default, rebuild))
         if name in self.config.values:
             raise ExtensionError('Config value %r already present' % name)
         if rebuild in (False, True):
@@ -370,13 +382,13 @@ class Sphinx(object):
         self.config.values[name] = (default, rebuild)
 
     def add_event(self, name):
-        self.debug('adding event: %r', name)
+        self.debug('[app] adding event: %r', name)
         if name in self._events:
             raise ExtensionError('Event %r already present' % name)
         self._events[name] = ''
 
     def add_node(self, node, **kwds):
-        self.debug('adding node: %r', (node, kwds))
+        self.debug('[app] adding node: %r', (node, kwds))
         nodes._add_node_class_names([node.__name__])
         for key, val in kwds.iteritems():
             try:
@@ -416,30 +428,30 @@ class Sphinx(object):
             return obj
 
     def add_directive(self, name, obj, content=None, arguments=None, **options):
-        self.debug('adding directive: %r',
+        self.debug('[app] adding directive: %r',
                    (name, obj, content, arguments, options))
         directives.register_directive(
             name, self._directive_helper(obj, content, arguments, **options))
 
     def add_role(self, name, role):
-        self.debug('adding role: %r', (name, role))
+        self.debug('[app] adding role: %r', (name, role))
         roles.register_local_role(name, role)
 
     def add_generic_role(self, name, nodeclass):
         # don't use roles.register_generic_role because it uses
         # register_canonical_role
-        self.debug('adding generic role: %r', (name, nodeclass))
+        self.debug('[app] adding generic role: %r', (name, nodeclass))
         role = roles.GenericRole(name, nodeclass)
         roles.register_local_role(name, role)
 
     def add_domain(self, domain):
-        self.debug('adding domain: %r', domain)
+        self.debug('[app] adding domain: %r', domain)
         if domain.name in self.domains:
             raise ExtensionError('domain %s already registered' % domain.name)
         self.domains[domain.name] = domain
 
     def override_domain(self, domain):
-        self.debug('overriding domain: %r', domain)
+        self.debug('[app] overriding domain: %r', domain)
         if domain.name not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain.name)
         if not issubclass(domain, self.domains[domain.name]):
@@ -449,7 +461,7 @@ class Sphinx(object):
 
     def add_directive_to_domain(self, domain, name, obj,
                                 content=None, arguments=None, **options):
-        self.debug('adding directive to domain: %r',
+        self.debug('[app] adding directive to domain: %r',
                    (domain, name, obj, content, arguments, options))
         if domain not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain)
@@ -457,13 +469,13 @@ class Sphinx(object):
             self._directive_helper(obj, content, arguments, **options)
 
     def add_role_to_domain(self, domain, name, role):
-        self.debug('adding role to domain: %r', (domain, name, role))
+        self.debug('[app] adding role to domain: %r', (domain, name, role))
         if domain not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain)
         self.domains[domain].roles[name] = role
 
     def add_index_to_domain(self, domain, index):
-        self.debug('adding index to domain: %r', (domain, index))
+        self.debug('[app] adding index to domain: %r', (domain, index))
         if domain not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain)
         self.domains[domain].indices.append(index)
@@ -471,7 +483,7 @@ class Sphinx(object):
     def add_object_type(self, directivename, rolename, indextemplate='',
                         parse_node=None, ref_nodeclass=None, objname='',
                         doc_field_types=[]):
-        self.debug('adding object type: %r',
+        self.debug('[app] adding object type: %r',
                    (directivename, rolename, indextemplate, parse_node,
                     ref_nodeclass, objname, doc_field_types))
         StandardDomain.object_types[directivename] = \
@@ -490,7 +502,7 @@ class Sphinx(object):
 
     def add_crossref_type(self, directivename, rolename, indextemplate='',
                           ref_nodeclass=None, objname=''):
-        self.debug('adding crossref type: %r',
+        self.debug('[app] adding crossref type: %r',
                    (directivename, rolename, indextemplate, ref_nodeclass,
                     objname))
         StandardDomain.object_types[directivename] = \
@@ -503,11 +515,11 @@ class Sphinx(object):
         StandardDomain.roles[rolename] = XRefRole(innernodeclass=ref_nodeclass)
 
     def add_transform(self, transform):
-        self.debug('adding transform: %r', transform)
+        self.debug('[app] adding transform: %r', transform)
         SphinxStandaloneReader.transforms.append(transform)
 
     def add_javascript(self, filename):
-        self.debug('adding javascript: %r', filename)
+        self.debug('[app] adding javascript: %r', filename)
         from sphinx.builders.html import StandaloneHTMLBuilder
         if '://' in filename:
             StandaloneHTMLBuilder.script_files.append(filename)
@@ -516,7 +528,7 @@ class Sphinx(object):
                 posixpath.join('_static', filename))
 
     def add_stylesheet(self, filename):
-        self.debug('adding stylesheet: %r', filename)
+        self.debug('[app] adding stylesheet: %r', filename)
         from sphinx.builders.html import StandaloneHTMLBuilder
         if '://' in filename:
             StandaloneHTMLBuilder.css_files.append(filename)
@@ -525,25 +537,25 @@ class Sphinx(object):
                 posixpath.join('_static', filename))
 
     def add_lexer(self, alias, lexer):
-        self.debug('adding lexer: %r', (alias, lexer))
+        self.debug('[app] adding lexer: %r', (alias, lexer))
         from sphinx.highlighting import lexers
         if lexers is None:
             return
         lexers[alias] = lexer
 
     def add_autodocumenter(self, cls):
-        self.debug('adding autodocumenter: %r', cls)
+        self.debug('[app] adding autodocumenter: %r', cls)
         from sphinx.ext import autodoc
         autodoc.add_documenter(cls)
         self.add_directive('auto' + cls.objtype, autodoc.AutoDirective)
 
     def add_autodoc_attrgetter(self, type, getter):
-        self.debug('adding autodoc attrgetter: %r', (type, getter))
+        self.debug('[app] adding autodoc attrgetter: %r', (type, getter))
         from sphinx.ext import autodoc
         autodoc.AutoDirective._special_attrgetters[type] = getter
 
     def add_search_language(self, cls):
-        self.debug('adding search language: %r', cls)
+        self.debug('[app] adding search language: %r', cls)
         from sphinx.search import languages, SearchLanguage
         assert isinstance(cls, SearchLanguage)
         languages[cls.lang] = cls