Merge lp:~gmb/maas/oo-logging-sexy into lp:~maas-committers/maas/trunk

[Graham Binns]

Put the maaslogger inside a get_maas_logger() function for the sake of sanity and customisation.

[Julian Edwards (julian-edwards)]

Nice work - just the stuff inline as discussed in person.

review: Approve

=== modified file 'src/maasfascist.py'
--- src/maasfascist.py	2014-07-21 20:12:28 +0000
+++ src/maasfascist.py	2014-07-29 14:38:06 +0000
@@ -33,7 +33,7 @@
 from inspect import (
     getmodule,
     getsourcefile,
-)
+    )
 from sys import (
     _getframe as getframe,
     meta_path,
 
=== modified file 'src/provisioningserver/import_images/tests/test_boot_resources.py'
--- src/provisioningserver/import_images/tests/test_boot_resources.py	2014-07-25 13:47:09 +0000
+++ src/provisioningserver/import_images/tests/test_boot_resources.py	2014-07-29 14:38:06 +0000
@@ -14,11 +14,11 @@
 __metaclass__ = type
 __all__ = []
 
-import errno
 from datetime import (
     datetime,
     timedelta,
     )
+import errno
 import hashlib
 import json
 import os
 
=== modified file 'src/provisioningserver/logger/log.py'
--- src/provisioningserver/logger/log.py	2014-07-29 09:36:01 +0000
+++ src/provisioningserver/logger/log.py	2014-07-29 14:38:06 +0000
@@ -13,16 +13,38 @@
 
 __metaclass__ = type
 __all__ = [
-    "maaslog",
+    "get_maas_logger",
     ]
 
 
 import logging
 from logging.handlers import SysLogHandler
 
-maaslog = logging.getLogger("maas")
-maaslog.setLevel(logging.DEBUG)
-handler = SysLogHandler("/dev/log")
-maaslog.addHandler(handler)
-formatter = logging.Formatter(fmt="maas: %(message)s")
-handler.setFormatter(formatter)
+
+def get_maas_logger(syslog_tag=None):
+    """Return a MAAS logger that will log to syslog.
+
+    :param syslog_tag: A string that will be used to prefix the message
+        in syslog. Will be appended to "maas" in the form
+        "maas.<syslog_tag>". If None, the syslog tag will simply be
+        "maas". syslog_tag is also used to name the logger with the
+        Python logging module; loggers will be named "maas.<syslog_tag>"
+        unless syslog_tag is None.
+    """
+    if syslog_tag is None:
+        logger_name = "maas"
+    else:
+        logger_name = "maas.%s" % syslog_tag
+    maaslog = logging.getLogger(logger_name)
+    # If the logger already has handlers, it's already been
+    # instantiated, so we don't need to go through the setup dance
+    # again.
+    if len(maaslog.handlers) > 0:
+        return maaslog
+
+    maaslog.setLevel(logging.DEBUG)
+    handler = SysLogHandler("/dev/log")
+    maaslog.addHandler(handler)
+    formatter = logging.Formatter(fmt=maaslog.name + ": %(message)s")
+    handler.setFormatter(formatter)
+    return maaslog
 
=== modified file 'src/provisioningserver/logger/tests/test_logger.py'
--- src/provisioningserver/logger/tests/test_logger.py	2014-07-29 09:36:01 +0000
+++ src/provisioningserver/logger/tests/test_logger.py	2014-07-29 14:38:06 +0000
@@ -14,24 +14,52 @@
 __metaclass__ = type
 __all__ = []
 
-import logging.handlers
+import logging
+
 from maastesting.factory import factory
 from maastesting.matchers import MockCalledOnceWith
+from provisioningserver.logger import log
+from provisioningserver.logger.log import get_maas_logger
 from provisioningserver.testing.testcase import PservTestCase
 
 
-class TestMAASLog(PservTestCase):
+class TestGetMAASLogger(PservTestCase):
 
-    def test_logs_to_syslog(self):
-        handler = self.patch(logging.handlers, 'SysLogHandler')
-        from provisioningserver.logger.log import maaslog
-        from provisioningserver.logger import log
+    def test_logger_logs_to_syslog(self):
+        handler = self.patch(log, 'SysLogHandler')
+        self.patch(logging, 'Formatter')
+        maaslog = get_maas_logger()
         random_log_text = factory.make_string()
         maaslog.warn(random_log_text)
         self.assertThat(
             handler.return_value.setFormatter,
-            MockCalledOnceWith(log.formatter))
+            MockCalledOnceWith(logging.Formatter.return_value))
         self.assertThat(
             handler, MockCalledOnceWith("/dev/log"))
         # For future hackers, handler.emit should be getting called here
         # but it's not.  NFI why.  HALP.
+
+    def test_adds_custom_formatting(self):
+        self.patch(log, 'SysLogHandler')
+        formatter = self.patch(logging, 'Formatter')
+        extra_formatting = factory.make_string()
+        get_maas_logger(extra_formatting)
+        self.assertThat(
+            formatter,
+            MockCalledOnceWith(
+                fmt=("maas.%s:" % extra_formatting) + " %(message)s"))
+
+    def test_sets_logger_name(self):
+        self.patch(log, 'SysLogHandler')
+        self.patch(logging, 'Formatter')
+        name = factory.make_string()
+        maaslog = get_maas_logger(name)
+        self.assertEqual("maas.%s" % name, maaslog.name)
+
+    def test_returns_same_logger_if_called_twice(self):
+        self.patch(log, 'SysLogHandler')
+        self.patch(logging, 'Formatter')
+        name = factory.make_string()
+        maaslog = get_maas_logger(name)
+        maaslog_2 = get_maas_logger(name)
+        self.assertIs(maaslog, maaslog_2)