config: Switch logging to new config system

mopidy/__main__.py

@@ -49,16 +49,18 @@ def main():
     config_overrides = options.overrides
 
     try:
-        # TODO: we need a two stage logging setup as we want logging for
-        # extension loading and config loading.
+        logging_config = load_config(config_files, config_overrides)
         log.setup_logging(
-            None, options.verbosity_level, options.save_debug_log)
+            logging_config, options.verbosity_level, options.save_debug_log)
         extensions = load_extensions()
         raw_config = load_config(config_files, config_overrides, extensions)
         extensions = filter_enabled_extensions(raw_config, extensions)
-        config = validate_config(raw_config, extensions)
+        config = validate_config(raw_config, config_schemas, extensions)
+        log.setup_log_levels(config)
         check_old_folders()
         setup_settings()
+        # Anything that wants to exit after this point must use
+        # process.exit_proces as actors have been started.
         audio = setup_audio(config)
         backends = setup_backends(config, extensions, audio)
         core = setup_core(audio, backends)
@@ -140,7 +142,7 @@ def show_config_callback(option, opt, value, parser):
     extensions = load_extensions()
     raw_config = load_config(files, overrides, extensions)
     enabled_extensions = filter_enabled_extensions(raw_config, extensions)
-    config = validate_config(raw_config, enabled_extensions)
+    config = validate_config(raw_config, config_schemas, enabled_extensions)
 
     output = []
     for section_name, schema in config_schemas.items():
@@ -235,22 +237,24 @@ def filter_enabled_extensions(raw_config, extensions):
     return enabled_extensions
 
 
-def load_config(files, overrides, extensions):
+def load_config(files, overrides, extensions=None):
     parser = configparser.RawConfigParser()
 
     files = [path.expand_path(f) for f in files]
     sources = ['builtin-defaults'] + files + ['command-line']
-    logging.info('Loading config from: %s', ', '.join(sources))
+    logger.info('Loading config from: %s', ', '.join(sources))
 
     # Read default core config
     parser.readfp(StringIO.StringIO(default_config))
 
     # Read default extension config
-    for extension in extensions:
+    for extension in extensions or []:
         parser.readfp(StringIO.StringIO(extension.get_default_config()))
 
     # Load config from a series of config files
     for filename in files:
+        # TODO: if this is the initial load of logging config we might not have
+        # a logger at this point, we might want to handle this better.
         try:
             filehandle = codecs.open(filename, encoding='utf-8')
             parser.readfp(filehandle)
@@ -259,7 +263,7 @@ def load_config(files, overrides, extensions):
             continue
         except UnicodeDecodeError:
             logger.error('Config file %s is not UTF-8 encoded', filename)
-            process.exit_process()
+            sys.exit(1)
 
     raw_config = {}
     for section in parser.sections():
@@ -271,10 +275,10 @@ def load_config(files, overrides, extensions):
     return raw_config
 
 
-def validate_config(raw_config, extensions):
+def validate_config(raw_config, schemas, extensions=None):
     # Collect config schemas to validate against
-    sections_and_schemas = config_schemas.items()
-    for extension in extensions:
+    sections_and_schemas = schemas.items()
+    for extension in extensions or []:
         sections_and_schemas.append(
             (extension.ext_name, extension.get_config_schema()))
 

mopidy/config.py

@@ -5,11 +5,12 @@ from mopidy.utils import config
 
 default_config = """
 [logging]
-console_format = %(levelname)-8s $(message)s
+console_format = %(levelname)-8s %(message)s
 debug_format = %(levelname)-8s %(asctime)s [%(process)d:%(threadName)s] %(name)s\n  %(message)s
 debug_file = mopidy.log
 
 [logging.levels]
+pykka = info
 
 [audio]
 mixer = autoaudiomixer

mopidy/frontends/http/__init__.py

@@ -32,6 +32,9 @@ port = 6680
 # "/mopidy" will continue to work as usual even if you change this setting.
 #
 static_dir =
+
+[logging.levels]
+cherrypy = warning
 """
 
 __doc__ = """

mopidy/utils/log.py

@@ -3,39 +3,44 @@ from __future__ import unicode_literals
 import logging
 import logging.handlers
 
-from mopidy import settings
 from . import deps, versioning
 
 
 def setup_logging(config, verbosity_level, save_debug_log):
     setup_root_logger()
-    setup_console_logging(verbosity_level)
+    setup_console_logging(config, verbosity_level)
     if save_debug_log:
-        setup_debug_logging_to_file()
+        setup_debug_logging_to_file(config)
     if hasattr(logging, 'captureWarnings'):
         # New in Python 2.7
         logging.captureWarnings(True)
+
     logger = logging.getLogger('mopidy.utils.log')
     logger.info('Starting Mopidy %s', versioning.get_version())
     logger.info('%(name)s: %(version)s', deps.platform_info())
     logger.info('%(name)s: %(version)s', deps.python_info())
 
 
+def setup_log_levels(config):
+    for name, level in config['logging.levels'].items():
+        logging.getLogger(name).setLevel(level)
+
+
 def setup_root_logger():
     root = logging.getLogger('')
     root.setLevel(logging.DEBUG)
 
 
-def setup_console_logging(verbosity_level):
+def setup_console_logging(config, verbosity_level):
     if verbosity_level == 0:
         log_level = logging.WARNING
-        log_format = settings.CONSOLE_LOG_FORMAT
+        log_format = config['logging']['console_format']
     elif verbosity_level >= 2:
         log_level = logging.DEBUG
-        log_format = settings.DEBUG_LOG_FORMAT
+        log_format = config['logging']['debug_format']
     else:
         log_level = logging.INFO
-        log_format = settings.CONSOLE_LOG_FORMAT
+        log_format = config['logging']['console_format']
     formatter = logging.Formatter(log_format)
     handler = logging.StreamHandler()
     handler.setFormatter(formatter)
@@ -43,17 +48,11 @@ def setup_console_logging(verbosity_level):
     root = logging.getLogger('')
     root.addHandler(handler)
 
-    if verbosity_level < 3:
-        logging.getLogger('pykka').setLevel(logging.INFO)
 
-    if verbosity_level < 2:
-        logging.getLogger('cherrypy').setLevel(logging.WARNING)
-
-
-def setup_debug_logging_to_file():
-    formatter = logging.Formatter(settings.DEBUG_LOG_FORMAT)
+def setup_debug_logging_to_file(config):
+    formatter = logging.Formatter(config['logging']['debug_format'])
     handler = logging.handlers.RotatingFileHandler(
-        settings.DEBUG_LOG_FILENAME, maxBytes=10485760, backupCount=3)
+        config['logging']['debug_file'], maxBytes=10485760, backupCount=3)
     handler.setFormatter(formatter)
     handler.setLevel(logging.DEBUG)
     root = logging.getLogger('')