Beginnings of better logging tests.

lib/iris/experimental/ugrid/__init__.py

@@ -1229,7 +1229,7 @@ def face_dimension(self, name):
                     "Not setting face_dimension (inappropriate for "
                     f"topology_dimension={self.topology_dimension} ."
                 )
-                logger.debug(message)
+                logger.debug(message, extra=dict(cls=None))
         elif not name or not isinstance(name, str):
             face_dimension = f"Mesh{self.topology_dimension}d_face"
         else:

lib/iris/tests/__init__.py

@@ -29,8 +29,8 @@
 import functools
 import gzip
 import inspect
-import json
 import io
+import json
 import math
 import os
 import os.path
@@ -607,6 +607,31 @@ def assertWarnsRegexp(self, expected_regexp=""):
         msg = msg.format(expected_regexp)
         self.assertTrue(matches, msg)
 
+    @contextlib.contextmanager
+    def assertLogs(self, logger=None, level=None):
+        """
+        An extended version of the usual :meth:`unittest.TestCase.assertLogs`,
+        which also exercises the logger's message formatting.
+
+        The inherited version of this method temporarily *replaces* the logger
+        in order to capture log records generated within the context.
+        However, in doing so it prevents any messages from being formatted
+        by the original logger.
+        This version first calls the original method, but then *also* exercises
+        the message formatters of all the logger's handlers, just to check that
+        there are no formatting errors.
+
+        """
+        # Invoke the standard assertLogs behaviour.
+        assertlogging_context = super().assertLogs(logger, level)
+        with assertlogging_context as watcher:
+            # Run the caller context, as per original method.
+            yield watcher
+        # Check for any formatting errors by running all the formatters.
+        for record in watcher.records:
+            for handler in assertlogging_context.logger.handlers:
+                handler.format(record)
+
     @contextlib.contextmanager
     def assertNoWarningsRegexp(self, expected_regexp=""):
         # Check that no warning matching the given expression is raised.

lib/iris/tests/unit/experimental/ugrid/test_Mesh.py

@@ -725,6 +725,8 @@ def test_dimension_names(self):
         default = ugrid.Mesh1DNames("Mesh1d_node", "Mesh1d_edge")
         self.assertEqual(default, self.mesh.dimension_names())
 
+        ugrid.logger.setLevel("DEBUG")
+        self.mesh.dimension_names("foo", "bar", "baz")
         with self.assertLogs(ugrid.logger, level="DEBUG") as log:
             self.mesh.dimension_names("foo", "bar", "baz")
             self.assertIn("Not setting face_dimension", log.output[0])
@@ -746,6 +748,8 @@ def test_edge_dimension_set(self):
         self.assertEqual("foo", self.mesh.edge_dimension)
 
     def test_face_dimension_set(self):
+        # ugrid.logger.setLevel('DEBUG')
+        # self.mesh.face_dimension = "foo"
         with self.assertLogs(ugrid.logger, level="DEBUG") as log:
             self.mesh.face_dimension = "foo"
             self.assertIn("Not setting face_dimension", log.output[0])