Merge pull request #3547 from jsiirola/logstream-loggeradapter

Support passing LoggerAdapter objects to LogStream

Author: jsiirola

pyomo/common/log.py

@@ -415,6 +415,8 @@ def redirect_streams(self, redirects):
         """
         found = 0
         logger = self._logger
+        while isinstance(logger, logging.LoggerAdapter):
+            logger = logger.logger
         while logger:
             for handler in logger.handlers:
                 found += 1

pyomo/common/tests/test_log.py

@@ -550,6 +550,18 @@ def test_log_stream(self):
             # Exiting the context manager flushes the LogStream
             self.assertEqual(OUT.getvalue(), "INFO: line 1\nINFO: line 2\n")
 
+    def test_loggerAdapter(self):
+        class Adapter(logging.LoggerAdapter):
+            def process(self, msg, kwargs):
+                return '[%s] %s' % (self.extra['foo'], msg), kwargs
+
+        adapter = Adapter(logging.getLogger('pyomo'), {"foo": 42})
+        ls = LogStream(logging.INFO, adapter)
+        LI = LoggingIntercept(level=logging.INFO, formatter=pyomo_formatter)
+        with LI as OUT:
+            ls.write("hello, world\n")
+            self.assertEqual(OUT.getvalue(), "INFO: [42] hello, world\n")
+
 
 class TestPreformatted(unittest.TestCase):
     def test_preformatted_api(self):

pyomo/common/tests/test_tee.py

@@ -422,6 +422,80 @@ def test_capture_fd_to_logger(self):
         finally:
             logger.propagate, logger.handlers = orig
 
+    def test_capture_to_logger_adapter(self):
+        class Adapter(logging.LoggerAdapter):
+            def process(self, msg, kwargs):
+                return '[%s] %s' % (self.extra['foo'], msg), kwargs
+
+        logger = logging.getLogger('_pyomo_no_logger')
+        adapter = Adapter(logger, {"foo": 42})
+        lstream = LogStream(logging.WARNING, adapter)
+        orig = logger.propagate, logger.handlers
+        try:
+            logger.propagate = False
+            logger.handlers = []
+            with LoggingIntercept(module='_pyomo_no_logger') as LOG:
+                with tee.capture_output(lstream, capture_fd=False):
+                    sys.stderr.write("hi!\n")
+                    sys.stderr.flush()
+            self.assertEqual(LOG.getvalue(), "[42] hi!\n")
+
+            # test that we handle the lastResort logger correctly
+            _lastResort = logging.lastResort
+            with tee.capture_output() as OUT:
+                with tee.capture_output(lstream, capture_fd=False):
+                    self.assertIsNot(_lastResort, logging.lastResort)
+                    sys.stderr.write("hi?\n")
+            self.assertEqual(OUT.getvalue(), "[42] hi?\n")
+
+            # test that we allow redirect-to-logger out
+            with tee.capture_output() as OUT:
+                logger.addHandler(logging.NullHandler())
+                logger.addHandler(logging.StreamHandler(sys.stderr))
+                with tee.capture_output(lstream, capture_fd=False):
+                    sys.stderr.write("hi.\n")
+            self.assertEqual(OUT.getvalue(), "[42] hi.\n")
+            logger.handlers.clear()
+        finally:
+            logger.propagate, logger.handlers = orig
+
+    def test_capture_fd_to_logger_adapter(self):
+        class Adapter(logging.LoggerAdapter):
+            def process(self, msg, kwargs):
+                return '[%s] %s' % (self.extra['foo'], msg), kwargs
+
+        logger = logging.getLogger('_pyomo_no_logger')
+        adapter = Adapter(logger, {"foo": 42})
+        lstream = LogStream(logging.WARNING, adapter)
+        orig = logger.propagate, logger.handlers
+        try:
+            logger.propagate = False
+            logger.handlers = []
+            with LoggingIntercept(module='_pyomo_no_logger') as LOG:
+                with tee.capture_output(lstream, capture_fd=True):
+                    sys.stderr.write("hi!\n")
+                    sys.stderr.flush()
+            self.assertEqual(LOG.getvalue(), "[42] hi!\n")
+
+            # test that we handle the lastResort logger correctly
+            _lastResort = logging.lastResort
+            with tee.capture_output() as OUT:
+                with tee.capture_output(lstream, capture_fd=True):
+                    self.assertIsNot(_lastResort, logging.lastResort)
+                    sys.stderr.write("hi?\n")
+            self.assertEqual(OUT.getvalue(), "[42] hi?\n")
+
+            # test that we allow redirect-to-logger out
+            with tee.capture_output() as OUT:
+                logger.addHandler(logging.NullHandler())
+                logger.addHandler(logging.StreamHandler(sys.stderr))
+                with tee.capture_output(lstream, capture_fd=True):
+                    sys.stderr.write("hi.\n")
+            self.assertEqual(OUT.getvalue(), "[42] hi.\n")
+            logger.handlers.clear()
+        finally:
+            logger.propagate, logger.handlers = orig
+
     def test_no_fileno_stdout(self):
         T = tee.capture_output()
         with T:

pyomo/opt/results/solution.py

@@ -89,7 +89,7 @@ def pprint(self, ostream, option, from_list=False, prefix="", repn=None):
         #
         # the following is specialized logic for handling variable and
         # constraint maps - which are dictionaries of dictionaries, with
-        # at a minimum an "id" element per sub-directionary.
+        # at a minimum an "id" element per sub-dictionary.
         #
         first = True
         for key in self._order: