From 06640f1f0cb351b6732162c8edd3e81cead41ee7 Mon Sep 17 00:00:00 2001
From: Stein Magnus Jodal <stein.magnus@jodal.no>
Date: Thu, 23 Jan 2014 22:35:24 +0100
Subject: [PATCH] log: Use custom filter to implement verbosity levels

...instead of hooking handlers onto multiple loggers with disabled propagation
from those loggers to parent loggers, breaking alternative log methods, like
custom setups through the the logging/config_file config value.

Fixes #661
---
 mopidy/__main__.py  |  3 +--
 mopidy/utils/log.py | 57 +++++++++++++++++++++------------------------
 2 files changed, 27 insertions(+), 33 deletions(-)

diff --git a/mopidy/__main__.py b/mopidy/__main__.py
index ac5e2102..1ddd76a4 100644
--- a/mopidy/__main__.py
+++ b/mopidy/__main__.py
@@ -70,8 +70,7 @@ def main():
         if args.verbosity_level:
             verbosity_level += args.verbosity_level
 
-        log.setup_logging(
-            config, installed_extensions, verbosity_level, args.save_debug_log)
+        log.setup_logging(config, verbosity_level, args.save_debug_log)
 
         enabled_extensions = []
         for extension in installed_extensions:
diff --git a/mopidy/utils/log.py b/mopidy/utils/log.py
index 867a2efa..c4045232 100644
--- a/mopidy/utils/log.py
+++ b/mopidy/utils/log.py
@@ -31,16 +31,14 @@ def bootstrap_delayed_logging():
     root.addHandler(_delayed_handler)
 
 
-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, extensions)
-
+def setup_logging(config, verbosity_level, save_debug_log):
     logging.captureWarnings(True)
 
+    setup_log_levels(config)
+    setup_console_logging(config, verbosity_level)
+    if save_debug_log:
+        setup_debug_logging_to_file(config)
+
     if config['logging']['config_file']:
         logging.config.fileConfig(config['logging']['config_file'])
 
@@ -61,46 +59,43 @@ LOG_LEVELS = {
 }
 
 
-def setup_console_logging(config, extensions, verbosity_level):
+class VerbosityFilter(logging.Filter):
+    def __init__(self, verbosity_level):
+        self.verbosity_level = verbosity_level
+
+    def filter(self, record):
+        if record.name.startswith('mopidy'):
+            required_log_level = LOG_LEVELS[self.verbosity_level]['mopidy']
+        else:
+            required_log_level = LOG_LEVELS[self.verbosity_level]['root']
+        return record.levelno >= required_log_level
+
+
+def setup_console_logging(config, 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())
 
+    verbosity_filter = VerbosityFilter(verbosity_level)
+
     if verbosity_level < 1:
         log_format = config['logging']['console_format']
     else:
         log_format = config['logging']['debug_format']
     formatter = logging.Formatter(log_format)
 
-    root_handler = logging.StreamHandler()
-    root_handler.setFormatter(formatter)
-    root_handler.setLevel(LOG_LEVELS[verbosity_level]['root'])
-    logging.getLogger('').addHandler(root_handler)
+    handler = logging.StreamHandler()
+    handler.addFilter(verbosity_filter)
+    handler.setFormatter(formatter)
 
-    mopidy_handler = logging.StreamHandler()
-    mopidy_handler.setFormatter(formatter)
-    mopidy_handler.setLevel(LOG_LEVELS[verbosity_level]['mopidy'])
-    add_mopidy_handler(extensions, mopidy_handler)
+    logging.getLogger('').addHandler(handler)
 
 
-def setup_debug_logging_to_file(config, extensions):
+def setup_debug_logging_to_file(config):
     formatter = logging.Formatter(config['logging']['debug_format'])
     handler = logging.handlers.RotatingFileHandler(
         config['logging']['debug_file'], maxBytes=10485760, backupCount=3)
     handler.setFormatter(formatter)
 
     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)