log: Add verbosity_level 2 and 3

Reduces the amount of dependency logging on level 1, and increases the amount
on level 2 and 3. Fixes #593.

mopidy/__main__.py

@@ -70,7 +70,8 @@ def main():
         if args.verbosity_level:
             verbosity_level += args.verbosity_level
 
-        log.setup_logging(config, verbosity_level, args.save_debug_log)
+        log.setup_logging(
+            config, installed_extensions, verbosity_level, args.save_debug_log)
 
         enabled_extensions = []
         for extension in installed_extensions:

mopidy/commands.py

@@ -241,7 +241,7 @@ class RootCommand(Command):
         self.add_argument(
             '-v', '--verbose',
             action='count', dest='verbosity_level', default=0,
-            help='more output (debug level)')
+            help='more output (repeat up to 3 times for even more)')
         self.add_argument(
             '--save-debug-log',
             action='store_true', dest='save_debug_log',

mopidy/utils/log.py

@@ -31,12 +31,13 @@ def bootstrap_delayed_logging():
     root.addHandler(_delayed_handler)
 
 
-def setup_logging(config, verbosity_level, save_debug_log):
-    setup_console_logging(config, verbosity_level)
+def setup_logging(config, extensions, verbosity_level, save_debug_log):
     setup_log_levels(config)
 
+    setup_console_logging(config, extensions, verbosity_level)
+
     if save_debug_log:
-        setup_debug_logging_to_file(config)
+        setup_debug_logging_to_file(config, extensions)
 
     logging.captureWarnings(True)
 
@@ -51,29 +52,55 @@ def setup_log_levels(config):
         logging.getLogger(name).setLevel(level)
 
 
-def setup_console_logging(config, verbosity_level):
-    if verbosity_level < 0:
-        log_level = logging.WARNING
+LOG_LEVELS = {
+    -1: dict(root=logging.ERROR, mopidy=logging.WARNING),
+    0: dict(root=logging.ERROR, mopidy=logging.INFO),
+    1: dict(root=logging.WARNING, mopidy=logging.DEBUG),
+    2: dict(root=logging.INFO, mopidy=logging.DEBUG),
+    3: dict(root=logging.DEBUG, mopidy=logging.DEBUG),
+}
+
+
+def setup_console_logging(config, extensions, verbosity_level):
+    if verbosity_level < min(LOG_LEVELS.keys()):
+        verbosity_level = min(LOG_LEVELS.keys())
+    if verbosity_level > max(LOG_LEVELS.keys()):
+        verbosity_level = max(LOG_LEVELS.keys())
+
+    if verbosity_level < 1:
         log_format = config['logging']['console_format']
-    elif verbosity_level >= 1:
-        log_level = logging.DEBUG
-        log_format = config['logging']['debug_format']
     else:
-        log_level = logging.INFO
-        log_format = config['logging']['console_format']
+        log_format = config['logging']['debug_format']
     formatter = logging.Formatter(log_format)
-    handler = logging.StreamHandler()
-    handler.setFormatter(formatter)
-    handler.setLevel(log_level)
-    root = logging.getLogger('')
-    root.addHandler(handler)
+
+    root_handler = logging.StreamHandler()
+    root_handler.setFormatter(formatter)
+    root_handler.setLevel(LOG_LEVELS[verbosity_level]['root'])
+    logging.getLogger('').addHandler(root_handler)
+
+    mopidy_handler = logging.StreamHandler()
+    mopidy_handler.setFormatter(formatter)
+    mopidy_handler.setLevel(LOG_LEVELS[verbosity_level]['mopidy'])
+    add_mopidy_handler(extensions, mopidy_handler)
 
 
-def setup_debug_logging_to_file(config):
+def setup_debug_logging_to_file(config, extensions):
     formatter = logging.Formatter(config['logging']['debug_format'])
     handler = logging.handlers.RotatingFileHandler(
         config['logging']['debug_file'], maxBytes=10485760, backupCount=3)
     handler.setFormatter(formatter)
-    handler.setLevel(logging.DEBUG)
-    root = logging.getLogger('')
-    root.addHandler(handler)
+
+    logging.getLogger('').addHandler(handler)
+
+    # We must add our handler explicitly, since the mopidy* handlers don't
+    # propagate to the root handler.
+    add_mopidy_handler(extensions, handler)
+
+
+def add_mopidy_handler(extensions, handler):
+    names = ['mopidy_%s' % ext.ext_name for ext in extensions]
+    names.append('mopidy')
+    for name in names:
+        logger = logging.getLogger(name)
+        logger.propagate = False
+        logger.addHandler(handler)