loggin: Add DelayedHandler to root logger.

The delayed handler:
- Accepts and buffers logs until they are released.
- Upon release the logs are re-posted to the root logger.
- After release log records are ignored.

This allows us to avoid the silly tricks we've been doing with parsing args and
config early for the sake of bootstraping logging. Now we can just start
logging and once the logging has been setup the messages are released and
handled according to the correct settings.

mopidy/__main__.py

@@ -21,12 +21,15 @@ from mopidy import commands, ext
 from mopidy.audio import Audio
 from mopidy import config as config_lib
 from mopidy.core import Core
-from mopidy.utils import deps, log, path, process
+from mopidy.utils import deps, log, path, process, versioning
 
 logger = logging.getLogger('mopidy.main')
 
 
 def main():
+    log.bootstrap_delayed_logging()
+    logger.info('Starting Mopidy %s', versioning.get_version())
+
     signal.signal(signal.SIGTERM, process.exit_handler)
     signal.signal(signal.SIGUSR1, pykka.debug.log_thread_tracebacks)
 
@@ -54,9 +57,14 @@ def main():
         # TODO: install extension subcommands.
 
         args = parser.parse_args(args=mopidy_args)
+        if args.command in ('deps', 'config'):
+            args.verbosity_level -= 1
+
         config, config_errors = config_lib.load(
             args.config_files, installed_extensions, args.config_overrides)
 
+        log.setup_logging(config, args.verbosity_level, args.save_debug_log)
+
         enabled_extensions = []
         for extension in installed_extensions:
             if not ext.validate_extension(extension):
@@ -92,7 +100,6 @@ def main():
         # Read-only config from here on, please.
         proxied_config = config_lib.Proxy(config)
 
-        log.setup_log_levels(proxied_config)
         ext.register_gstreamer_elements(enabled_extensions)
 
         # Anything that wants to exit after this point must use

mopidy/utils/log.py

@@ -4,14 +4,40 @@ import logging
 import logging.config
 import logging.handlers
 
-from . import versioning
+
+class DelayedHandler(logging.Handler):
+    def __init__(self):
+        logging.Handler.__init__(self)
+        self._released = False
+        self._buffer = []
+
+    def handle(self, record):
+        if not self._released:
+            self._buffer.append(record)
+
+    def release(self):
+        self._released = True
+        root = logging.getLogger('')
+        while self._buffer:
+            root.handle(self._buffer.pop(0))
+
+
+_delayed_handler = DelayedHandler()
+
+
+def bootstrap_delayed_logging():
+    root = logging.getLogger('')
+    root.setLevel(logging.DEBUG)
+    root.addHandler(_delayed_handler)
 
 
 def setup_logging(config, verbosity_level, save_debug_log):
-    setup_root_logger()
     setup_console_logging(config, verbosity_level)
+    setup_log_levels(config)
+
     if save_debug_log:
         setup_debug_logging_to_file(config)
+
     if hasattr(logging, 'captureWarnings'):
         # New in Python 2.7
         logging.captureWarnings(True)
@@ -19,8 +45,7 @@ def setup_logging(config, verbosity_level, save_debug_log):
     if config['logging']['config_file']:
         logging.config.fileConfig(config['logging']['config_file'])
 
-    logger = logging.getLogger('mopidy.utils.log')
-    logger.info('Starting Mopidy %s', versioning.get_version())
+    _delayed_handler.release()
 
 
 def setup_log_levels(config):
@@ -28,11 +53,6 @@ def setup_log_levels(config):
         logging.getLogger(name).setLevel(level)
 
 
-def setup_root_logger():
-    root = logging.getLogger('')
-    root.setLevel(logging.DEBUG)
-
-
 def setup_console_logging(config, verbosity_level):
     if verbosity_level < 0:
         log_level = logging.WARNING