Add verbose option `-v` for sphinx-build and some rudimentary debugging support.

CHANGES

@@ -1,6 +1,12 @@
 Release 1.2 (in development)
 ============================
 
+* sphinx-build now has a verbose option :option:`-v` which can be
+  repeated for greater effect.  A single occurrance provides a
+  slightly more verbose output than normal.  Two or more occurrences
+  of this option provides more detailed output which may be useful for
+  debugging.
+
 * sphinx-build now provides more specific error messages when called with
   invalid options or arguments.
 

sphinx/application.py

@@ -61,7 +61,8 @@ class Sphinx(object):
 
     def __init__(self, srcdir, confdir, outdir, doctreedir, buildername,
                  confoverrides=None, status=sys.stdout, warning=sys.stderr,
-                 freshenv=False, warningiserror=False, tags=None):
+                 freshenv=False, warningiserror=False, tags=None, verbosity=0):
+        self.verbosity = verbosity
         self.next_listener_id = 0
         self._extensions = {}
         self._listeners = {}
@@ -214,6 +215,17 @@ class Sphinx(object):
             self.emit('build-finished', None)
         self.builder.cleanup()
 
+    def _log(self, message, wfile, nonl=False):
+        try:
+            wfile.write(message)
+        except UnicodeEncodeError:
+            encoding = getattr(wfile, 'encoding', 'ascii') or 'ascii'
+            wfile.write(message.encode(encoding, 'replace'))
+        if not nonl:
+            wfile.write('\n')
+        if hasattr(wfile, 'flush'):
+            wfile.flush()
+
     def warn(self, message, location=None, prefix='WARNING: '):
         if isinstance(location, tuple):
             docname, lineno = location
@@ -226,26 +238,30 @@ class Sphinx(object):
         if self.warningiserror:
             raise SphinxWarning(warntext)
         self._warncount += 1
-        try:
+        self._log(warntext, self._warning, True)
-            self._warning.write(warntext)
-        except UnicodeEncodeError:
-            encoding = getattr(self._warning, 'encoding', 'ascii') or 'ascii'
-            self._warning.write(warntext.encode(encoding, 'replace'))
 
     def info(self, message='', nonl=False):
-        try:
+        self._log(message, self._status, nonl)
-            self._status.write(message)
+
-        except UnicodeEncodeError:
+    def verbose(self, message, *args, **kwargs):
-            encoding = getattr(self._status, 'encoding', 'ascii') or 'ascii'
+        if self.verbosity < 1:
-            self._status.write(message.encode(encoding, 'replace'))
+            return
-        if not nonl:
+        if args or kwargs:
-            self._status.write('\n')
+            message = message % (args or kwargs)
-        self._status.flush()
+        self._log(message, self._warning)
+
+    def debug(self, message, *args, **kwargs):
+        if self.verbosity < 2:
+            return
+        if args or kwargs:
+            message = message % (args or kwargs)
+        self._log(message, self._warning)
 
     # 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)
         if extension in self._extensions:
             return
         try:
@@ -306,9 +322,12 @@ class Sphinx(object):
         else:
             self._listeners[event][listener_id] = callback
         self.next_listener_id += 1
+        self.debug('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)
         for event in self._listeners.itervalues():
             event.pop(listener_id, None)
 
@@ -328,6 +347,7 @@ class Sphinx(object):
     # registering addon parts
 
     def add_builder(self, builder):
+        self.debug('adding builder: %r', builder)
         if not hasattr(builder, 'name'):
             raise ExtensionError('Builder class %s has no "name" attribute'
                                  % builder)
@@ -342,6 +362,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))
         if name in self.config.values:
             raise ExtensionError('Config value %r already present' % name)
         if rebuild in (False, True):
@@ -349,11 +370,13 @@ class Sphinx(object):
         self.config.values[name] = (default, rebuild)
 
     def add_event(self, name):
+        self.debug('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))
         nodes._add_node_class_names([node.__name__])
         for key, val in kwds.iteritems():
             try:
@@ -393,24 +416,30 @@ class Sphinx(object):
             return obj
 
     def add_directive(self, name, obj, content=None, arguments=None, **options):
+        self.debug('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))
         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))
         role = roles.GenericRole(name, nodeclass)
         roles.register_local_role(name, role)
 
     def add_domain(self, domain):
+        self.debug('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)
         if domain.name not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain.name)
         if not issubclass(domain, self.domains[domain.name]):
@@ -420,17 +449,21 @@ class Sphinx(object):
 
     def add_directive_to_domain(self, domain, name, obj,
                                 content=None, arguments=None, **options):
+        self.debug('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)
         self.domains[domain].directives[name] = \
             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))
         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))
         if domain not in self.domains:
             raise ExtensionError('domain %s not yet registered' % domain)
         self.domains[domain].indices.append(index)
@@ -438,6 +471,9 @@ 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',
+                   (directivename, rolename, indextemplate, parse_node,
+                    ref_nodeclass, objname, doc_field_types))
         StandardDomain.object_types[directivename] = \
             ObjType(objname or directivename, rolename)
         # create a subclass of GenericObject as the new directive
@@ -454,6 +490,9 @@ class Sphinx(object):
 
     def add_crossref_type(self, directivename, rolename, indextemplate='',
                           ref_nodeclass=None, objname=''):
+        self.debug('adding crossref type: %r',
+                   (directivename, rolename, indextemplate, ref_nodeclass,
+                    objname))
         StandardDomain.object_types[directivename] = \
             ObjType(objname or directivename, rolename)
         # create a subclass of Target as the new directive
@@ -464,9 +503,11 @@ class Sphinx(object):
         StandardDomain.roles[rolename] = XRefRole(innernodeclass=ref_nodeclass)
 
     def add_transform(self, transform):
+        self.debug('adding transform: %r', transform)
         SphinxStandaloneReader.transforms.append(transform)
 
     def add_javascript(self, filename):
+        self.debug('adding javascript: %r', filename)
         from sphinx.builders.html import StandaloneHTMLBuilder
         if '://' in filename:
             StandaloneHTMLBuilder.script_files.append(filename)
@@ -475,6 +516,7 @@ class Sphinx(object):
                 posixpath.join('_static', filename))
 
     def add_stylesheet(self, filename):
+        self.debug('adding stylesheet: %r', filename)
         from sphinx.builders.html import StandaloneHTMLBuilder
         if '://' in filename:
             StandaloneHTMLBuilder.css_files.append(filename)
@@ -483,21 +525,25 @@ class Sphinx(object):
                 posixpath.join('_static', filename))
 
     def add_lexer(self, alias, lexer):
+        self.debug('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)
         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))
         from sphinx.ext import autodoc
         autodoc.AutoDirective._special_attrgetters[type] = getter
 
     def add_search_language(self, cls):
+        self.debug('adding search language: %r', cls)
         from sphinx.search import languages, SearchLanguage
         assert isinstance(cls, SearchLanguage)
         languages[cls.lang] = cls

sphinx/builders/__init__.py

@@ -119,9 +119,13 @@ class Builder(object):
         summary = bold(summary)
         for item in iterable:
             l += 1
-            self.info(term_width_line('%s[%3d%%] %s' %
+            s = '%s[%3d%%] %s' % (summary, 100*l/length,
-                                      (summary, 100*l/length,
+                                  colorfunc(item))
-                                       colorfunc(item))), nonl=1)
+            if self.app.verbosity:
+                s += '\n'
+            else:
+                s = term_width_line(s)
+            self.info(s, nonl=1)
             yield item
         if l > 0:
             self.info()

sphinx/cmdline.py

@@ -60,6 +60,7 @@ new and changed files
          -W        -- turn warnings into errors
          -P        -- run Pdb on exception
          -T        -- show full traceback on exception
+         -v        -- increase verbosity (can be repeated)
         --help     -- show this help and exit
         --version  -- show version information and exit
 Modi:
@@ -74,7 +75,7 @@ def main(argv):
         nocolor()
 
     try:
-        opts, args = getopt.getopt(argv[1:], 'ab:t:d:c:CD:A:ng:NEqQWw:PTh',
+        opts, args = getopt.getopt(argv[1:], 'ab:t:d:c:CD:A:ng:NEqQWw:PThv',
                                    ['help', 'version'])
         allopts = set(opt[0] for opt in opts)
         if '-h' in allopts or '--help' in allopts:
@@ -123,6 +124,7 @@ def main(argv):
     buildername = None
     force_all = freshenv = warningiserror = use_pdb = False
     show_traceback = False
+    verbosity = 0
     status = sys.stdout
     warning = sys.stderr
     error = sys.stderr
@@ -201,6 +203,9 @@ def main(argv):
             use_pdb = True
         elif opt == '-T':
             show_traceback = True
+        elif opt == '-v':
+            verbosity += 1
+            show_traceback = True
 
     if warning and warnfile:
         warnfp = open(warnfile, 'w')
@@ -210,7 +215,7 @@ def main(argv):
     try:
         app = Sphinx(srcdir, confdir, outdir, doctreedir, buildername,
                      confoverrides, status, warning, freshenv,
-                     warningiserror, tags)
+                     warningiserror, tags, verbosity)
         app.build(force_all, filenames)
         return app.statuscode
     except (Exception, KeyboardInterrupt), err:

sphinx/environment.py

@@ -951,6 +951,7 @@ class BuildEnvironment:
         filterlevel = self.config.keep_warnings and 2 or 5
         for node in doctree.traverse(nodes.system_message):
             if node['level'] < filterlevel:
+                self.app.debug('%s [filtered system message]', node.astext())
                 node.parent.remove(node)
 
 

sphinx/util/__init__.py

@@ -291,6 +291,12 @@ class Tee(object):
         self.stream1.write(text)
         self.stream2.write(text)
 
+    def flush(self):
+        if hasattr(self.stream1, 'flush'):
+            self.stream1.flush()
+        if hasattr(self.stream2, 'flush'):
+            self.stream2.flush()
+
 
 def parselinenos(spec, total):
     """Parse a line number spec (such as "1,2,4-6") and return a list of