Logging: Implemented PEP 391.

1 files changed, 664 insertions, 9 deletions

diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py
index e06a97d..25127c0 100644
--- a/Lib/test/test_logging.py
+++ b/Lib/test/test_logging.py
@@ -30,6 +30,7 @@ import copy
 import cPickle
 import cStringIO
 import gc
+import json
 import os
 import re
 import select
@@ -85,6 +86,10 @@ class BaseTest(unittest.TestCase):
         level."""
         self.stream.close()
         self.root_logger.removeHandler(self.root_hdlr)
+        while self.root_logger.handlers:
+            h = self.root_logger.handlers[0]
+            self.root_logger.removeHandler(h)
+            h.close()
         self.root_logger.setLevel(self.original_logging_level)
         logging._acquireLock()
         try:
@@ -632,14 +637,8 @@ class ConfigFileTest(BaseTest):
     """
 
     def apply_config(self, conf):
-        try:
-            fn = tempfile.mktemp(".ini")
-            f = open(fn, "w")
-            f.write(textwrap.dedent(conf))
-            f.close()
-            logging.config.fileConfig(fn)
-        finally:
-            os.remove(fn)
+        file = cStringIO.StringIO(textwrap.dedent(conf))
+        logging.config.fileConfig(file)
 
     def test_config0_ok(self):
         # A simple config file which overrides the default settings.
@@ -938,6 +937,662 @@ class WarningsTest(BaseTest):
             finally:
                 logging.captureWarnings(False)
 
+
+def formatFunc(format, datefmt=None):
+    return logging.Formatter(format, datefmt)
+
+def handlerFunc():
+    return logging.StreamHandler()
+
+class CustomHandler(logging.StreamHandler):
+    pass
+
+class ConfigDictTest(BaseTest):
+
+    """Reading logging config from a dictionary."""
+
+    expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
+
+    # config0 is a standard configuration.
+    config0 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+            'handlers' : ['hand1'],
+        },
+    }
+
+    # config1 adds a little to the standard configuration.
+    config1 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    # config2 has a subtle configuration error that should be reported
+    config2 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdbout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    #As config1 but with a misspelt level on a handler
+    config2a = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NTOSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+
+    #As config1 but with a misspelt level on a logger
+    config2b = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WRANING',
+        },
+    }
+
+    # config3 has a less subtle configuration error
+    config3 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'misspelled_name',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    # config4 specifies a custom formatter class to be loaded
+    config4 = {
+        'formatters': {
+            'form1' : {
+                '()' : __name__ + '.ExceptionFormatter',
+                'format' : '%(levelname)s:%(name)s:%(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'root' : {
+            'level' : 'NOTSET',
+                'handlers' : ['hand1'],
+        },
+    }
+
+    # As config4 but using an actual callable rather than a string
+    config4a = {
+        'formatters': {
+            'form1' : {
+                '()' : ExceptionFormatter,
+                'format' : '%(levelname)s:%(name)s:%(message)s',
+            },
+            'form2' : {
+                '()' : __name__ + '.formatFunc',
+                'format' : '%(levelname)s:%(name)s:%(message)s',
+            },
+            'form3' : {
+                '()' : formatFunc,
+                'format' : '%(levelname)s:%(name)s:%(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+            'hand2' : {
+                '()' : handlerFunc,
+            },
+        },
+        'root' : {
+            'level' : 'NOTSET',
+                'handlers' : ['hand1'],
+        },
+    }
+
+    # config5 specifies a custom handler class to be loaded
+    config5 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : __name__ + '.CustomHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    # config6 specifies a custom handler class to be loaded
+    # but has bad arguments
+    config6 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : __name__ + '.CustomHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+                '9' : 'invalid parameter name',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    #config 7 does not define compiler.parser but defines compiler.lexer
+    #so compiler.parser should be disabled after applying it
+    config7 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.lexer' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    config8 = {
+        'disable_existing_loggers' : False,
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler' : {
+                'level' : 'DEBUG',
+                'handlers' : ['hand1'],
+            },
+            'compiler.lexer' : {
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+        },
+    }
+
+    config9 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'WARNING',
+                'stream'  : 'ext://sys.stdout',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'WARNING',
+                'handlers' : ['hand1'],
+            },
+        },
+        'root' : {
+            'level' : 'NOTSET',
+        },
+    }
+
+    config9a = {
+        'incremental' : True,
+        'handlers' : {
+            'hand1' : {
+                'level' : 'WARNING',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'INFO',
+            },
+        },
+    }
+
+    config9b = {
+        'incremental' : True,
+        'handlers' : {
+            'hand1' : {
+                'level' : 'INFO',
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'INFO',
+            },
+        },
+    }
+
+    #As config1 but with a filter added
+    config10 = {
+        'formatters': {
+            'form1' : {
+                'format' : '%(levelname)s ++ %(message)s',
+            },
+        },
+        'filters' : {
+            'filt1' : {
+                'name' : 'compiler.parser',
+            },
+        },
+        'handlers' : {
+            'hand1' : {
+                'class' : 'logging.StreamHandler',
+                'formatter' : 'form1',
+                'level' : 'NOTSET',
+                'stream'  : 'ext://sys.stdout',
+                'filters' : ['filt1'],
+            },
+        },
+        'loggers' : {
+            'compiler.parser' : {
+                'level' : 'DEBUG',
+                'filters' : ['filt1'],
+            },
+        },
+        'root' : {
+            'level' : 'WARNING',
+            'handlers' : ['hand1'],
+        },
+    }
+
+    def apply_config(self, conf):
+        logging.config.dictConfig(conf)
+
+    def test_config0_ok(self):
+        # A simple config which overrides the default settings.
+        with captured_stdout() as output:
+            self.apply_config(self.config0)
+            logger = logging.getLogger()
+            # Won't output anything
+            logger.info(self.next_message())
+            # Outputs a message
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('ERROR', '2'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+
+    def test_config1_ok(self, config=config1):
+        # A config defining a sub-parser as well.
+        with captured_stdout() as output:
+            self.apply_config(config)
+            logger = logging.getLogger("compiler.parser")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '1'),
+                ('ERROR', '2'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+
+    def test_config2_failure(self):
+        # A simple config which overrides the default settings.
+        self.assertRaises(StandardError, self.apply_config, self.config2)
+
+    def test_config2a_failure(self):
+        # A simple config which overrides the default settings.
+        self.assertRaises(StandardError, self.apply_config, self.config2a)
+
+    def test_config2b_failure(self):
+        # A simple config which overrides the default settings.
+        self.assertRaises(StandardError, self.apply_config, self.config2b)
+
+    def test_config3_failure(self):
+        # A simple config which overrides the default settings.
+        self.assertRaises(StandardError, self.apply_config, self.config3)
+
+    def test_config4_ok(self):
+        # A config specifying a custom formatter class.
+        with captured_stdout() as output:
+            self.apply_config(self.config4)
+            #logger = logging.getLogger()
+            try:
+                raise RuntimeError()
+            except RuntimeError:
+                logging.exception("just testing")
+            sys.stdout.seek(0)
+            self.assertEquals(output.getvalue(),
+                "ERROR:root:just testing\nGot a [RuntimeError]\n")
+            # Original logger output is empty
+            self.assert_log_lines([])
+
+    def test_config4a_ok(self):
+        # A config specifying a custom formatter class.
+        with captured_stdout() as output:
+            self.apply_config(self.config4a)
+            #logger = logging.getLogger()
+            try:
+                raise RuntimeError()
+            except RuntimeError:
+                logging.exception("just testing")
+            sys.stdout.seek(0)
+            self.assertEquals(output.getvalue(),
+                "ERROR:root:just testing\nGot a [RuntimeError]\n")
+            # Original logger output is empty
+            self.assert_log_lines([])
+
+    def test_config5_ok(self):
+        self.test_config1_ok(config=self.config5)
+
+    def test_config6_failure(self):
+        self.assertRaises(StandardError, self.apply_config, self.config6)
+
+    def test_config7_ok(self):
+        with captured_stdout() as output:
+            self.apply_config(self.config1)
+            logger = logging.getLogger("compiler.parser")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '1'),
+                ('ERROR', '2'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+        with captured_stdout() as output:
+            self.apply_config(self.config7)
+            logger = logging.getLogger("compiler.parser")
+            self.assertTrue(logger.disabled)
+            logger = logging.getLogger("compiler.lexer")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '3'),
+                ('ERROR', '4'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+
+    #Same as test_config_7_ok but don't disable old loggers.
+    def test_config_8_ok(self):
+        with captured_stdout() as output:
+            self.apply_config(self.config1)
+            logger = logging.getLogger("compiler.parser")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '1'),
+                ('ERROR', '2'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+        with captured_stdout() as output:
+            self.apply_config(self.config8)
+            logger = logging.getLogger("compiler.parser")
+            self.assertFalse(logger.disabled)
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            logger = logging.getLogger("compiler.lexer")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '3'),
+                ('ERROR', '4'),
+                ('INFO', '5'),
+                ('ERROR', '6'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+
+    def test_config_9_ok(self):
+        with captured_stdout() as output:
+            self.apply_config(self.config9)
+            logger = logging.getLogger("compiler.parser")
+            #Nothing will be output since both handler and logger are set to WARNING
+            logger.info(self.next_message())
+            self.assert_log_lines([], stream=output)
+            self.apply_config(self.config9a)
+            #Nothing will be output since both handler is still set to WARNING
+            logger.info(self.next_message())
+            self.assert_log_lines([], stream=output)
+            self.apply_config(self.config9b)
+            #Message should now be output
+            logger.info(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '3'),
+            ], stream=output)
+
+    def test_config_10_ok(self):
+        with captured_stdout() as output:
+            self.apply_config(self.config10)
+            logger = logging.getLogger("compiler.parser")
+            logger.warning(self.next_message())
+            logger = logging.getLogger('compiler')
+            #Not output, because filtered
+            logger.warning(self.next_message())
+            logger = logging.getLogger('compiler.lexer')
+            #Not output, because filtered
+            logger.warning(self.next_message())
+            logger = logging.getLogger("compiler.parser.codegen")
+            #Output, as not filtered
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('WARNING', '1'),
+                ('ERROR', '4'),
+            ], stream=output)
+
+    def setup_via_listener(self, text):
+        PORT = 9030
+        t = logging.config.listen(PORT)
+        t.start()
+
+        sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
+        sock.connect(('localhost', PORT))
+
+        slen = struct.pack('>L', len(text))
+        s = slen + text
+        sentsofar = 0
+        left = len(s)
+        while left > 0:
+            sent = sock.send(s[sentsofar:])
+            sentsofar += sent
+            left -= sent
+        sock.close()
+        logging.config.stopListening()
+        t.join()
+
+    def test_listen_config_10_ok(self):
+        with captured_stdout() as output:
+            self.setup_via_listener(json.dumps(self.config10))
+            logger = logging.getLogger("compiler.parser")
+            logger.warning(self.next_message())
+            logger = logging.getLogger('compiler')
+            #Not output, because filtered
+            logger.warning(self.next_message())
+            logger = logging.getLogger('compiler.lexer')
+            #Not output, because filtered
+            logger.warning(self.next_message())
+            logger = logging.getLogger("compiler.parser.codegen")
+            #Output, as not filtered
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('WARNING', '1'),
+                ('ERROR', '4'),
+            ], stream=output)
+
+    def test_listen_config_1_ok(self):
+        with captured_stdout() as output:
+            self.setup_via_listener(textwrap.dedent(ConfigFileTest.config1))
+            logger = logging.getLogger("compiler.parser")
+            # Both will output a message
+            logger.info(self.next_message())
+            logger.error(self.next_message())
+            self.assert_log_lines([
+                ('INFO', '1'),
+                ('ERROR', '2'),
+            ], stream=output)
+            # Original logger output is empty.
+            self.assert_log_lines([])
+
+
 # Set the locale to the platform-dependent default.  I have no idea
 # why the test does this, but in any case we save the current locale
 # first and restore it at the end.
@@ -946,7 +1601,7 @@ def test_main():
     run_unittest(BuiltinLevelsTest, BasicFilterTest,
                     CustomLevelsAndFiltersTest, MemoryHandlerTest,
                     ConfigFileTest, SocketHandlerTest, MemoryTest,
-                    EncodingTest, WarningsTest)
+                    EncodingTest, WarningsTest, ConfigDictTest)
 
 if __name__ == "__main__":
     test_main()