Add tests for MDC in log messages

lsst · Jul 24, 2021 · d198762 · d198762
1 parent 7577771
commit d198762
Show file tree

Hide file tree

Showing 2 changed files with 46 additions and 1 deletion.
diff --git a/python/lsst/daf/butler/core/logging.py b/python/lsst/daf/butler/core/logging.py
@@ -259,6 +259,10 @@ def format(self, log_format: Optional[str] = None) -> str:
 
         as_dict = self.dict()
 
+        # Special case MDC content. Convert it to an MDCDict
+        # so that missing items do not break formatting.
+        as_dict["MDC"] = MDCDict(as_dict["MDC"])
+
         as_dict["asctime"] = as_dict["asctime"].isoformat()
         formatted = log_format.format(**as_dict)
         return formatted

diff --git a/tests/test_logging.py b/tests/test_logging.py
@@ -25,7 +25,14 @@
 import tempfile
 from logging import StreamHandler, FileHandler
 
-from lsst.daf.butler import ButlerLogRecordHandler, ButlerLogRecords, VERBOSE, JsonFormatter, ButlerLogRecord
+from lsst.daf.butler import (
+    ButlerLogRecordHandler,
+    ButlerLogRecords,
+    VERBOSE,
+    JsonFormatter,
+    ButlerLogRecord,
+    ButlerMDC,
+)
 
 
 class LoggingTestCase(unittest.TestCase):
@@ -40,6 +47,7 @@ def setUp(self):
     def tearDown(self):
         if self.handler and self.log:
             self.log.removeHandler(self.handler)
+        ButlerMDC.restore_log_record_factory()
 
     def testRecordCapture(self):
         """Test basic log capture and serialization."""
@@ -170,6 +178,39 @@ def testExceptionInfo(self):
 
         self.assertIn("Debug exception", self.handler.records[-1].exc_info)
 
+    def testMDC(self):
+        """Test that MDC information appears in messages."""
+        self.log.setLevel(logging.INFO)
+
+        i = 0
+        self.log.info("Message %d", i)
+        i += 1
+        self.assertEqual(self.handler.records[-1].MDC, {})
+
+        ButlerMDC.add_mdc_log_record_factory()
+        label = "MDC value"
+        ButlerMDC.MDC("LABEL", label)
+        self.log.info("Message %d", i)
+        self.assertEqual(self.handler.records[-1].MDC["LABEL"], label)
+
+        # Change the label and check that the previous record does not
+        # itself change.
+        ButlerMDC.MDC("LABEL", "dataId")
+        self.assertEqual(self.handler.records[-1].MDC["LABEL"], label)
+
+        # Format a record with MDC.
+        record = self.handler.records[-1]
+
+        # By default the MDC label should not be involved.
+        self.assertNotIn(label, str(record))
+
+        # But it can be included.
+        fmt = "x{MDC[LABEL]}"
+        self.assertEqual(record.format(fmt), "x" + label)
+
+        # But can be optional on a record that didn't set it.
+        self.assertEqual(self.handler.records[0].format(fmt), "x")
+
 
 class TestJsonLogging(unittest.TestCase):