From 37edcec5661fd95e700bda56631ee8eef5c49c1b Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Thu, 22 Apr 2021 16:37:48 +0100 Subject: [PATCH 1/6] More correct use of logging. --- lib/iris/experimental/ugrid/__init__.py | 32 +++++++++++++------ ...test_CFUGridAuxiliaryCoordinateVariable.py | 12 +++---- .../ugrid/test_CFUGridConnectivityVariable.py | 12 ++++--- .../ugrid/test_CFUGridMeshVariable.py | 11 ++++--- 4 files changed, 42 insertions(+), 25 deletions(-) diff --git a/lib/iris/experimental/ugrid/__init__.py b/lib/iris/experimental/ugrid/__init__.py index b0f0d8c533..fb3b2d84bc 100644 --- a/lib/iris/experimental/ugrid/__init__.py +++ b/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=self.__class__.__name__)) elif not name or not isinstance(name, str): face_dimension = f"Mesh{self.topology_dimension}d_face" else: @@ -3332,7 +3332,11 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"{name}, referenced by netCDF variable " f"{nc_var_name}" ) - logger.debug(message) + # TODO: reconsider logging level when we + # have consistent practice. + logger.warning( + message, extra=dict(cls=cls.__name__) + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3346,7 +3350,9 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"as a CF-UGRID connectivity - is a " f"CF-netCDF label variable." ) - logger.debug(message) + logger.debug( + message, extra=dict(cls=cls.__name__) + ) return result @@ -3403,7 +3409,11 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"referenced by netCDF variable " f"{nc_var_name}" ) - logger.debug(message) + # TODO: reconsider logging level when we + # have consistent practice. + logger.warning( + message, extra=dict(cls=cls.__name__) + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3420,7 +3430,9 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"coordinate - is a CF-netCDF label " f"variable." ) - logger.debug(message) + logger.debug( + message, extra=dict(cls=cls.__name__) + ) return result @@ -3467,7 +3479,11 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"Missing CF-UGRID mesh variable {name}, " f"referenced by netCDF variable {nc_var_name}" ) - logger.debug(message) + # TODO: reconsider logging level when we have + # consistent practice. + logger.warning( + message, extra=dict(cls=cls.__name__) + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3481,7 +3497,7 @@ def identify(cls, variables, ignore=None, target=None, warn=True): f"CF-UGRID mesh - is a CF-netCDF label " f"variable." ) - logger.debug(message) + logger.debug(message, extra=dict(cls=cls.__name__)) return result @@ -3673,7 +3689,6 @@ def _build_mesh(cf, mesh_var, file_path): ", consistent with the attached connectivities." ) # TODO: reconsider logging level when we have consistent practice. - # TODO: logger always requires extras['cls'] : can we fix this? logger.warning(msg, extra=dict(cls=None)) else: quoted_topology_dimension = mesh_var.topology_dimension @@ -3687,7 +3702,6 @@ def _build_mesh(cf, mesh_var, file_path): " -- ignoring this as it is inconsistent." ) # TODO: reconsider logging level when we have consistent practice. - # TODO: logger always requires extras['cls'] : can we fix this? logger.warning(msg=msg, extra=dict(cls=None)) node_dimension = None diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py index a0e5c5e3f2..9f5f2ced52 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py @@ -214,19 +214,19 @@ def test_warn(self): } # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: + with self.assertLogs(logger) as log: result = CFUGridAuxiliaryCoordinateVariable.identify( vars_all, warn=False ) - self.assertEqual(0, len(log.output)) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - self.assertIn( - f"Missing CF-netCDF auxiliary coordinate variable {subject_name}", - log.output[0], - ) + rec = log.records[0] + self.assertEqual("WARNING", rec.levelname) + re_msg = rf"Missing CF-netCDF auxiliary coordinate variable {subject_name}.*" + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) # String variable warning. diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py index 5cf40026cb..5cbb9f2af4 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py @@ -203,17 +203,19 @@ def test_warn(self): } # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: + with self.assertLogs(logger) as log: result = CFUGridConnectivityVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.output)) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridConnectivityVariable.identify(vars_all) - self.assertIn( - f"Missing CF-UGRID connectivity variable {subject_name}", - log.output[0], + rec = log.records[0] + self.assertEqual("WARNING", rec.levelname) + re_msg = ( + rf"Missing CF-UGRID connectivity variable {subject_name}.*" ) + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) # String variable warning. diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py index 79601b8604..935621ae40 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py @@ -196,16 +196,17 @@ def test_warn(self): } # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: + with self.assertLogs(logger) as log: result = CFUGridMeshVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.output)) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridMeshVariable.identify(vars_all) - self.assertIn( - f"Missing CF-UGRID mesh variable {subject_name}", log.output[0] - ) + rec = log.records[0] + self.assertEqual("WARNING", rec.levelname) + re_msg = rf"Missing CF-UGRID mesh variable {subject_name}.*" + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) # String variable warning. From e1f4b96dcb3c4f57f7a0cea2edfeab6fa22524a4 Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Thu, 22 Apr 2021 17:05:41 +0100 Subject: [PATCH 2/6] Improvements to all log unit tests. --- ...test_CFUGridAuxiliaryCoordinateVariable.py | 6 ++- .../ugrid/test_CFUGridConnectivityVariable.py | 6 ++- .../ugrid/test_CFUGridMeshVariable.py | 6 ++- .../unit/experimental/ugrid/test_Mesh.py | 44 ++++++++++++++----- .../fileformats/netcdf/test_load_cubes.py | 5 ++- 5 files changed, 53 insertions(+), 14 deletions(-) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py index 9f5f2ced52..9effaba480 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py @@ -237,9 +237,13 @@ def test_warn(self): result = CFUGridAuxiliaryCoordinateVariable.identify( vars_all, warn=False ) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - self.assertIn("is a CF-netCDF label variable", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r".*is a CF-netCDF label variable.*" + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py index 5cbb9f2af4..fc2ee38fbc 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py @@ -224,9 +224,13 @@ def test_warn(self): subject_name, "", np.bytes_ ) result = CFUGridConnectivityVariable.identify(vars_all, warn=False) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridConnectivityVariable.identify(vars_all) - self.assertIn("is a CF-netCDF label variable", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r".*is a CF-netCDF label variable.*" + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py index 935621ae40..b7176234a8 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py @@ -215,9 +215,13 @@ def test_warn(self): subject_name, "", np.bytes_ ) result = CFUGridMeshVariable.identify(vars_all, warn=False) + self.assertEqual(0, len(log.records)) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridMeshVariable.identify(vars_all) - self.assertIn("is a CF-netCDF label variable", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r".*is a CF-netCDF label variable.*" + self.assertRegex(rec.msg, re_msg) self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py index 9848809206..a2abb2124f 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py @@ -194,7 +194,10 @@ def test_connectivities_locations(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.assertEqual([], func(contains_face=True)) - self.assertIn("filter for non-existent", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r".*filter for non-existent.*" + self.assertRegex(rec.msg, re_msg) def test_coord(self): # See Mesh.coords tests for thorough coverage of cases. @@ -266,7 +269,10 @@ def test_coords_locations(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.assertEqual([], func(include_faces=True)) - self.assertIn("filter non-existent", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r".*filter non-existent.*" + self.assertRegex(rec.msg, re_msg) def test_edge_dimension(self): self.assertEqual( @@ -620,7 +626,10 @@ def test_add_connectivities_invalid(self): face_node = self.FACE_NODE with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.add_connectivities(face_node) - self.assertIn("Not adding connectivity", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Not adding connectivity.*" + self.assertRegex(rec.msg, re_msg) def test_add_coords(self): # ADD coords. @@ -727,7 +736,10 @@ def test_dimension_names(self): 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]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Not setting face_dimension.*" + self.assertRegex(rec.msg, re_msg) self.assertEqual( ugrid.Mesh1DNames("foo", "bar"), self.mesh.dimension_names() ) @@ -748,7 +760,10 @@ def test_edge_dimension_set(self): def test_face_dimension_set(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.face_dimension = "foo" - self.assertIn("Not setting face_dimension", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Not setting face_dimension.*" + self.assertRegex(rec.msg, re_msg) self.assertIsNone(self.mesh.face_dimension) def test_node_dimension_set(self): @@ -793,14 +808,17 @@ def test_remove_connectivities(self): for kwargs in positive_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.remove_connectivities(**kwargs) - self.assertIn("Ignoring request to remove", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Ignoring request to remove.*" + self.assertRegex(rec.msg, re_msg) self.assertEqual(self.EDGE_NODE, self.mesh.edge_node_connectivity) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: # Check that the only debug log is the one we inserted. ugrid.logger.debug("foo") self.mesh.remove_connectivities(**kwargs) - self.assertEqual(1, len(log.output)) + self.assertEqual(1, len(log.records)) self.assertEqual(self.EDGE_NODE, self.mesh.edge_node_connectivity) def test_remove_coords(self): @@ -828,14 +846,17 @@ def test_remove_coords(self): for kwargs in positive_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.remove_coords(**kwargs) - self.assertIn("Ignoring request to remove", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Ignoring request to remove.*" + self.assertRegex(rec.msg, re_msg) self.assertEqual(self.NODE_LON, self.mesh.node_coords.node_x) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: # Check that the only debug log is the one we inserted. ugrid.logger.debug("foo") self.mesh.remove_coords(**kwargs) - self.assertEqual(1, len(log.output)) + self.assertEqual(1, len(log.records)) self.assertEqual(self.NODE_LON, self.mesh.node_coords.node_x) # Test removal of optional connectivity. @@ -947,7 +968,10 @@ def test_add_connectivities_invalid(self): ) with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.add_connectivities(fake_cf_role) - self.assertIn("Not adding connectivity", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"Not adding connectivity.*" + self.assertRegex(rec.msg, re_msg) def test_add_coords_face(self): # ADD coords. diff --git a/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py b/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py index 5ed908bfd0..ca1976398d 100644 --- a/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py +++ b/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py @@ -316,4 +316,7 @@ def test_missing_mesh(self): with PARSE_UGRID_ON_LOAD.context(): with self.assertLogs(logger, level="DEBUG") as log: _ = list(load_cubes(nc_path)) - self.assertIn("File does not contain mesh", log.output[0]) + rec = log.records[0] + self.assertEqual("DEBUG", rec.levelname) + re_msg = r"File does not contain mesh.*" + self.assertRegex(rec.msg, re_msg) From 24cbc6619011ad3614f1af36bb7a5907dfbac9c4 Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Fri, 23 Apr 2021 14:50:47 +0100 Subject: [PATCH 3/6] CFUGRidVariable logging better integration with warn parameter. --- lib/iris/experimental/ugrid/__init__.py | 99 ++++++++++--------- ...test_CFUGridAuxiliaryCoordinateVariable.py | 25 ++--- .../ugrid/test_CFUGridConnectivityVariable.py | 29 +++--- .../ugrid/test_CFUGridMeshVariable.py | 25 ++--- 4 files changed, 99 insertions(+), 79 deletions(-) diff --git a/lib/iris/experimental/ugrid/__init__.py b/lib/iris/experimental/ugrid/__init__.py index fb3b2d84bc..8eefedb6ea 100644 --- a/lib/iris/experimental/ugrid/__init__.py +++ b/lib/iris/experimental/ugrid/__init__.py @@ -15,6 +15,7 @@ from collections.abc import Iterable from contextlib import contextmanager from functools import wraps +import logging import re import threading @@ -3313,6 +3314,8 @@ class CFUGridConnectivityVariable(cf.CFVariable): def identify(cls, variables, ignore=None, target=None, warn=True): result = {} ignore, target = cls._identify_common(variables, ignore, target) + # TODO: reconsider logging level when we have consistent practice. + log_level = logging.WARNING if warn else logging.DEBUG # Identify all CF-UGRID connectivity variables. for nc_var_name, nc_var in target.items(): @@ -3326,17 +3329,16 @@ def identify(cls, variables, ignore=None, target=None, warn=True): name = nc_var_att.strip() if name not in ignore: if name not in variables: - if warn: - message = ( - f"Missing CF-UGRID connectivity variable " - f"{name}, referenced by netCDF variable " - f"{nc_var_name}" - ) - # TODO: reconsider logging level when we - # have consistent practice. - logger.warning( - message, extra=dict(cls=cls.__name__) - ) + message = ( + f"Missing CF-UGRID connectivity variable " + f"{name}, referenced by netCDF variable " + f"{nc_var_name}" + ) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3344,14 +3346,16 @@ def identify(cls, variables, ignore=None, target=None, warn=True): result[name] = CFUGridConnectivityVariable( name, variables[name] ) - elif warn: + else: message = ( f"Ignoring variable {name}, identified " f"as a CF-UGRID connectivity - is a " f"CF-netCDF label variable." ) - logger.debug( - message, extra=dict(cls=cls.__name__) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), ) return result @@ -3391,6 +3395,8 @@ class CFUGridAuxiliaryCoordinateVariable(cf.CFVariable): def identify(cls, variables, ignore=None, target=None, warn=True): result = {} ignore, target = cls._identify_common(variables, ignore, target) + # TODO: reconsider logging level when we have consistent practice. + log_level = logging.WARNING if warn else logging.DEBUG # Identify any CF-UGRID-relevant auxiliary coordinate variables. for nc_var_name, nc_var in target.items(): @@ -3402,18 +3408,16 @@ def identify(cls, variables, ignore=None, target=None, warn=True): for name in nc_var_att.split(): if name not in ignore: if name not in variables: - if warn: - message = ( - f"Missing CF-netCDF auxiliary " - f"coordinate variable {name}, " - f"referenced by netCDF variable " - f"{nc_var_name}" - ) - # TODO: reconsider logging level when we - # have consistent practice. - logger.warning( - message, extra=dict(cls=cls.__name__) - ) + message = ( + f"Missing CF-netCDF auxiliary coordinate " + f"variable {name}, referenced by netCDF " + f"variable {nc_var_name}" + ) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3423,15 +3427,17 @@ def identify(cls, variables, ignore=None, target=None, warn=True): ] = CFUGridAuxiliaryCoordinateVariable( name, variables[name] ) - elif warn: + else: message = ( f"Ignoring variable {name}, " - f"identified as a CF-netCDF auxiliary " - f"coordinate - is a CF-netCDF label " - f"variable." + f"identified as a CF-netCDF " + f"auxiliary coordinate - is a " + f"CF-netCDF label variable." ) - logger.debug( - message, extra=dict(cls=cls.__name__) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), ) return result @@ -3463,6 +3469,8 @@ class CFUGridMeshVariable(cf.CFVariable): def identify(cls, variables, ignore=None, target=None, warn=True): result = {} ignore, target = cls._identify_common(variables, ignore, target) + # TODO: reconsider logging level when we have consistent practice. + log_level = logging.WARNING if warn else logging.DEBUG # Identify all CF-UGRID mesh variables. for nc_var_name, nc_var in target.items(): @@ -3474,16 +3482,15 @@ def identify(cls, variables, ignore=None, target=None, warn=True): name = nc_var_att.strip() if name not in ignore: if name not in variables: - if warn: - message = ( - f"Missing CF-UGRID mesh variable {name}, " - f"referenced by netCDF variable {nc_var_name}" - ) - # TODO: reconsider logging level when we have - # consistent practice. - logger.warning( - message, extra=dict(cls=cls.__name__) - ) + message = ( + f"Missing CF-UGRID mesh variable {name}, " + f"referenced by netCDF variable {nc_var_name}" + ) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), + ) else: # Restrict to non-string type i.e. not a # CFLabelVariable. @@ -3491,13 +3498,17 @@ def identify(cls, variables, ignore=None, target=None, warn=True): result[name] = CFUGridMeshVariable( name, variables[name] ) - elif warn: + else: message = ( f"Ignoring variable {name}, identified as a " f"CF-UGRID mesh - is a CF-netCDF label " f"variable." ) - logger.debug(message, extra=dict(cls=cls.__name__)) + logger.log( + level=log_level, + msg=message, + extra=dict(cls=cls.__name__), + ) return result diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py index 9effaba480..21cc260370 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py @@ -213,37 +213,40 @@ def test_warn(self): "ref_source": ref_source, } + def check_log(expected_levelname, log_regex): + rec = log.records[-1] + self.assertEqual(expected_levelname, rec.levelname) + self.assertRegex(rec.msg, log_regex) + # Missing warning. - with self.assertLogs(logger) as log: + with self.assertLogs(logger, level="DEBUG") as log: + log_regex = rf"Missing CF-netCDF auxiliary coordinate variable {subject_name}.*" + result = CFUGridAuxiliaryCoordinateVariable.identify( vars_all, warn=False ) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("WARNING", rec.levelname) - re_msg = rf"Missing CF-netCDF auxiliary coordinate variable {subject_name}.*" - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) # String variable warning. with self.assertLogs(logger, level="DEBUG") as log: + log_regex = r".*is a CF-netCDF label variable.*" vars_all[subject_name] = netcdf_ugrid_variable( subject_name, "", np.bytes_ ) + result = CFUGridAuxiliaryCoordinateVariable.identify( vars_all, warn=False ) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r".*is a CF-netCDF label variable.*" - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py index fc2ee38fbc..91fa962955 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py @@ -202,35 +202,38 @@ def test_warn(self): "ref_source": ref_source, } + def check_log(expected_levelname, log_regex): + rec = log.records[-1] + self.assertEqual(expected_levelname, rec.levelname) + self.assertRegex(rec.msg, log_regex) + # Missing warning. - with self.assertLogs(logger) as log: + with self.assertLogs(logger, level="DEBUG") as log: + log_regex = ( + rf"Missing CF-UGRID connectivity variable {subject_name}.*" + ) + result = CFUGridConnectivityVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridConnectivityVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("WARNING", rec.levelname) - re_msg = ( - rf"Missing CF-UGRID connectivity variable {subject_name}.*" - ) - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) # String variable warning. with self.assertLogs(logger, level="DEBUG") as log: + log_regex = r".*is a CF-netCDF label variable.*" vars_all[subject_name] = netcdf_ugrid_variable( subject_name, "", np.bytes_ ) + result = CFUGridConnectivityVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridConnectivityVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r".*is a CF-netCDF label variable.*" - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py index b7176234a8..3a2651ebce 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py @@ -195,33 +195,36 @@ def test_warn(self): "ref_source": ref_source, } + def check_log(expected_levelname, log_regex): + rec = log.records[-1] + self.assertEqual(expected_levelname, rec.levelname) + self.assertRegex(rec.msg, log_regex) + # Missing warning. - with self.assertLogs(logger) as log: + with self.assertLogs(logger, level="DEBUG") as log: + log_regex = rf"Missing CF-UGRID mesh variable {subject_name}.*" + result = CFUGridMeshVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridMeshVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("WARNING", rec.levelname) - re_msg = rf"Missing CF-UGRID mesh variable {subject_name}.*" - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) # String variable warning. with self.assertLogs(logger, level="DEBUG") as log: + log_regex = r".*is a CF-netCDF label variable.*" vars_all[subject_name] = netcdf_ugrid_variable( subject_name, "", np.bytes_ ) + result = CFUGridMeshVariable.identify(vars_all, warn=False) - self.assertEqual(0, len(log.records)) + check_log("DEBUG", log_regex) self.assertDictEqual({}, result) # Default is warn=True result = CFUGridMeshVariable.identify(vars_all) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r".*is a CF-netCDF label variable.*" - self.assertRegex(rec.msg, re_msg) + check_log("WARNING", log_regex) self.assertDictEqual({}, result) From bfbed13737fe3099aef67864a26cd8dd38b30e96 Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Tue, 27 Apr 2021 15:46:46 +0100 Subject: [PATCH 4/6] Iris-specific extension to AssertLogs(). --- lib/iris/tests/__init__.py | 25 +++++++++++++++++++ .../unit/experimental/ugrid/test_Mesh.py | 4 +-- 2 files changed, 27 insertions(+), 2 deletions(-) diff --git a/lib/iris/tests/__init__.py b/lib/iris/tests/__init__.py index b2eebc4f03..2ce9769bcc 100644 --- a/lib/iris/tests/__init__.py +++ b/lib/iris/tests/__init__.py @@ -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. diff --git a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py index a2abb2124f..9b5f4e64e4 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py @@ -816,7 +816,7 @@ def test_remove_connectivities(self): for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: # Check that the only debug log is the one we inserted. - ugrid.logger.debug("foo") + ugrid.logger.debug("foo", extra=dict(cls=None)) self.mesh.remove_connectivities(**kwargs) self.assertEqual(1, len(log.records)) self.assertEqual(self.EDGE_NODE, self.mesh.edge_node_connectivity) @@ -854,7 +854,7 @@ def test_remove_coords(self): for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: # Check that the only debug log is the one we inserted. - ugrid.logger.debug("foo") + ugrid.logger.debug("foo", extra=dict(cls=None)) self.mesh.remove_coords(**kwargs) self.assertEqual(1, len(log.records)) self.assertEqual(self.NODE_LON, self.mesh.node_coords.node_x) From 3cf66627856db2214eeeae05ff4a61a349172449 Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Tue, 27 Apr 2021 16:09:35 +0100 Subject: [PATCH 5/6] Simplified test_Mesh log checking. --- .../unit/experimental/ugrid/test_Mesh.py | 45 ++++++------------- 1 file changed, 13 insertions(+), 32 deletions(-) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py index 9b5f4e64e4..b14720e9da 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py @@ -69,6 +69,11 @@ def setUpClass(cls): [[0, 1], [1, 2], [2, 0]], cf_role="boundary_node_connectivity" ) + def check_log(self, log, expected_levelname, log_regex): + rec = log.records[-1] + self.assertEqual(expected_levelname, rec.levelname) + self.assertRegex(rec.msg, log_regex) + class TestProperties1D(TestMeshCommon): # Tests that can re-use a single instance for greater efficiency. @@ -194,10 +199,7 @@ def test_connectivities_locations(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.assertEqual([], func(contains_face=True)) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r".*filter for non-existent.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r".*filter for non-existent.*") def test_coord(self): # See Mesh.coords tests for thorough coverage of cases. @@ -269,10 +271,7 @@ def test_coords_locations(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.assertEqual([], func(include_faces=True)) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r".*filter non-existent.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r".*filter non-existent.*") def test_edge_dimension(self): self.assertEqual( @@ -626,10 +625,7 @@ def test_add_connectivities_invalid(self): face_node = self.FACE_NODE with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.add_connectivities(face_node) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Not adding connectivity.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Not adding connectivity.*") def test_add_coords(self): # ADD coords. @@ -736,10 +732,7 @@ def test_dimension_names(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.dimension_names("foo", "bar", "baz") - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Not setting face_dimension.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Not setting face_dimension.*") self.assertEqual( ugrid.Mesh1DNames("foo", "bar"), self.mesh.dimension_names() ) @@ -760,10 +753,7 @@ def test_edge_dimension_set(self): def test_face_dimension_set(self): with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.face_dimension = "foo" - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Not setting face_dimension.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Not setting face_dimension.*") self.assertIsNone(self.mesh.face_dimension) def test_node_dimension_set(self): @@ -808,10 +798,7 @@ def test_remove_connectivities(self): for kwargs in positive_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.remove_connectivities(**kwargs) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Ignoring request to remove.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Ignoring request to remove.*") self.assertEqual(self.EDGE_NODE, self.mesh.edge_node_connectivity) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: @@ -846,10 +833,7 @@ def test_remove_coords(self): for kwargs in positive_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.remove_coords(**kwargs) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Ignoring request to remove.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Ignoring request to remove.*") self.assertEqual(self.NODE_LON, self.mesh.node_coords.node_x) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: @@ -968,10 +952,7 @@ def test_add_connectivities_invalid(self): ) with self.assertLogs(ugrid.logger, level="DEBUG") as log: self.mesh.add_connectivities(fake_cf_role) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"Not adding connectivity.*" - self.assertRegex(rec.msg, re_msg) + self.check_log(log, "DEBUG", r"Not adding connectivity.*") def test_add_coords_face(self): # ADD coords. From 5a997d333175ded17c2f9202f849a6cb2317e6c1 Mon Sep 17 00:00:00 2001 From: Martin Yeo Date: Tue, 27 Apr 2021 19:55:28 +0100 Subject: [PATCH 6/6] Added regex convenience to Iris tests AssertLogs(). --- lib/iris/fileformats/netcdf.py | 2 +- lib/iris/tests/__init__.py | 13 ++++- .../experimental/test_ugrid_load.py | 18 ++----- ...test_CFUGridAuxiliaryCoordinateVariable.py | 52 +++++++------------ .../ugrid/test_CFUGridConnectivityVariable.py | 50 +++++++----------- .../ugrid/test_CFUGridMeshVariable.py | 44 ++++++---------- .../unit/experimental/ugrid/test_Mesh.py | 41 +++++++-------- .../fileformats/netcdf/test_load_cubes.py | 7 +-- 8 files changed, 92 insertions(+), 135 deletions(-) diff --git a/lib/iris/fileformats/netcdf.py b/lib/iris/fileformats/netcdf.py index 5486c3a9db..00a207b86d 100644 --- a/lib/iris/fileformats/netcdf.py +++ b/lib/iris/fileformats/netcdf.py @@ -52,7 +52,7 @@ DEBUG = False # Configure the logger. -logger = iris.config.get_logger(__name__, fmt="[%(cls)s.%(funcName)s]") +logger = iris.config.get_logger(__name__) # Pyke CF related file names. _PYKE_RULE_BASE = "fc_rules_cf" diff --git a/lib/iris/tests/__init__.py b/lib/iris/tests/__init__.py index 2ce9769bcc..7c7adf12ce 100644 --- a/lib/iris/tests/__init__.py +++ b/lib/iris/tests/__init__.py @@ -608,11 +608,15 @@ def assertWarnsRegexp(self, expected_regexp=""): self.assertTrue(matches, msg) @contextlib.contextmanager - def assertLogs(self, logger=None, level=None): + def assertLogs(self, logger=None, level=None, msg_regex=None): """ An extended version of the usual :meth:`unittest.TestCase.assertLogs`, which also exercises the logger's message formatting. + Also adds the ``msg_regex`` kwarg: + If used, check that the result is a single message of the specified + level, and that it matches this regex. + 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 @@ -632,6 +636,13 @@ def assertLogs(self, logger=None, level=None): for handler in assertlogging_context.logger.handlers: handler.format(record) + # Check message, if requested. + if msg_regex: + self.assertEqual(len(watcher.records), 1) + rec = watcher.records[0] + self.assertEqual(level, rec.levelname) + self.assertRegex(rec.msg, msg_regex) + @contextlib.contextmanager def assertNoWarningsRegexp(self, expected_regexp=""): # Check that no warning matching the given expression is raised. diff --git a/lib/iris/tests/integration/experimental/test_ugrid_load.py b/lib/iris/tests/integration/experimental/test_ugrid_load.py index aa73103130..6886418fb6 100644 --- a/lib/iris/tests/integration/experimental/test_ugrid_load.py +++ b/lib/iris/tests/integration/experimental/test_ugrid_load.py @@ -155,36 +155,26 @@ def create_synthetic_file(self, **create_kwargs): def test_mesh_bad_topology_dimension(self): # Check that the load generates a suitable warning. - with self.assertLogs(logger) as log: + log_regex = r"topology_dimension.* ignoring" + with self.assertLogs(logger, level="WARNING", msg_regex=log_regex): template = "minimal_bad_topology_dim" dim_line = "mesh_var:topology_dimension = 1 ;" # which is wrong ! cube = self.create_synthetic_test_cube( template=template, subs=dict(TOPOLOGY_DIM_DEFINITION=dim_line) ) - # Check we got just one message, and its content - self.assertEqual(len(log.records), 1) - rec = log.records[0] - self.assertEqual(rec.levelname, "WARNING") - re_msg = r"topology_dimension.* ignoring" - self.assertRegex(rec.msg, re_msg) # Check that the result has topology-dimension of 2 (not 1). self.assertEqual(cube.mesh.topology_dimension, 2) def test_mesh_no_topology_dimension(self): # Check that the load generates a suitable warning. - with self.assertLogs(logger) as log: + log_regex = r"Mesh variable.* has no 'topology_dimension'" + with self.assertLogs(logger, level="WARNING", msg_regex=log_regex): template = "minimal_bad_topology_dim" dim_line = "" # don't create ANY topology_dimension property cube = self.create_synthetic_test_cube( template=template, subs=dict(TOPOLOGY_DIM_DEFINITION=dim_line) ) - # Check we got just one message, and its content - self.assertEqual(len(log.records), 1) - rec = log.records[0] - self.assertEqual(rec.levelname, "WARNING") - re_msg = r"Mesh variable.* has no 'topology_dimension'" - self.assertRegex(rec.msg, re_msg) # Check that the result has the correct topology-dimension value. self.assertEqual(cube.mesh.topology_dimension, 2) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py index 21cc260370..bb593dc25e 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridAuxiliaryCoordinateVariable.py @@ -213,40 +213,26 @@ def test_warn(self): "ref_source": ref_source, } - def check_log(expected_levelname, log_regex): - rec = log.records[-1] - self.assertEqual(expected_levelname, rec.levelname) - self.assertRegex(rec.msg, log_regex) + # The warn kwarg and expected corresponding log level. + warn_and_level = {True: "WARNING", False: "DEBUG"} # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = rf"Missing CF-netCDF auxiliary coordinate variable {subject_name}.*" - - result = CFUGridAuxiliaryCoordinateVariable.identify( - vars_all, warn=False - ) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = rf"Missing CF-netCDF auxiliary coordinate variable {subject_name}.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + result = CFUGridAuxiliaryCoordinateVariable.identify( + vars_all, warn=warn + ) + self.assertDictEqual({}, result) # String variable warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = r".*is a CF-netCDF label variable.*" - vars_all[subject_name] = netcdf_ugrid_variable( - subject_name, "", np.bytes_ - ) - - result = CFUGridAuxiliaryCoordinateVariable.identify( - vars_all, warn=False - ) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridAuxiliaryCoordinateVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = r".*is a CF-netCDF label variable.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + vars_all[subject_name] = netcdf_ugrid_variable( + subject_name, "", np.bytes_ + ) + result = CFUGridAuxiliaryCoordinateVariable.identify( + vars_all, warn=warn + ) + self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py index 91fa962955..d24870c49b 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridConnectivityVariable.py @@ -202,38 +202,26 @@ def test_warn(self): "ref_source": ref_source, } - def check_log(expected_levelname, log_regex): - rec = log.records[-1] - self.assertEqual(expected_levelname, rec.levelname) - self.assertRegex(rec.msg, log_regex) + # The warn kwarg and expected corresponding log level. + warn_and_level = {True: "WARNING", False: "DEBUG"} # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = ( - rf"Missing CF-UGRID connectivity variable {subject_name}.*" - ) - - result = CFUGridConnectivityVariable.identify(vars_all, warn=False) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridConnectivityVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = rf"Missing CF-UGRID connectivity variable {subject_name}.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + result = CFUGridConnectivityVariable.identify( + vars_all, warn=warn + ) + self.assertDictEqual({}, result) # String variable warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = r".*is a CF-netCDF label variable.*" - vars_all[subject_name] = netcdf_ugrid_variable( - subject_name, "", np.bytes_ - ) - - result = CFUGridConnectivityVariable.identify(vars_all, warn=False) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridConnectivityVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = r".*is a CF-netCDF label variable.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + vars_all[subject_name] = netcdf_ugrid_variable( + subject_name, "", np.bytes_ + ) + result = CFUGridConnectivityVariable.identify( + vars_all, warn=warn + ) + self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py index 3a2651ebce..b89a341ccc 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_CFUGridMeshVariable.py @@ -195,36 +195,22 @@ def test_warn(self): "ref_source": ref_source, } - def check_log(expected_levelname, log_regex): - rec = log.records[-1] - self.assertEqual(expected_levelname, rec.levelname) - self.assertRegex(rec.msg, log_regex) + # The warn kwarg and expected corresponding log level. + warn_and_level = {True: "WARNING", False: "DEBUG"} # Missing warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = rf"Missing CF-UGRID mesh variable {subject_name}.*" - - result = CFUGridMeshVariable.identify(vars_all, warn=False) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridMeshVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = rf"Missing CF-UGRID mesh variable {subject_name}.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + result = CFUGridMeshVariable.identify(vars_all, warn=warn) + self.assertDictEqual({}, result) # String variable warning. - with self.assertLogs(logger, level="DEBUG") as log: - log_regex = r".*is a CF-netCDF label variable.*" - vars_all[subject_name] = netcdf_ugrid_variable( - subject_name, "", np.bytes_ - ) - - result = CFUGridMeshVariable.identify(vars_all, warn=False) - check_log("DEBUG", log_regex) - self.assertDictEqual({}, result) - - # Default is warn=True - result = CFUGridMeshVariable.identify(vars_all) - check_log("WARNING", log_regex) - self.assertDictEqual({}, result) + log_regex = r".*is a CF-netCDF label variable.*" + for warn, level in warn_and_level.items(): + with self.assertLogs(logger, level=level, msg_regex=log_regex): + vars_all[subject_name] = netcdf_ugrid_variable( + subject_name, "", np.bytes_ + ) + result = CFUGridMeshVariable.identify(vars_all, warn=warn) + self.assertDictEqual({}, result) diff --git a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py index b14720e9da..fa118ec082 100644 --- a/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py +++ b/lib/iris/tests/unit/experimental/ugrid/test_Mesh.py @@ -69,11 +69,6 @@ def setUpClass(cls): [[0, 1], [1, 2], [2, 0]], cf_role="boundary_node_connectivity" ) - def check_log(self, log, expected_levelname, log_regex): - rec = log.records[-1] - self.assertEqual(expected_levelname, rec.levelname) - self.assertRegex(rec.msg, log_regex) - class TestProperties1D(TestMeshCommon): # Tests that can re-use a single instance for greater efficiency. @@ -197,9 +192,9 @@ def test_connectivities_locations(self): for kwargs in negative_kwargs: self.assertEqual([], func(**kwargs)) - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r".*filter for non-existent.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.assertEqual([], func(contains_face=True)) - self.check_log(log, "DEBUG", r".*filter for non-existent.*") def test_coord(self): # See Mesh.coords tests for thorough coverage of cases. @@ -269,9 +264,9 @@ def test_coords_locations(self): expected = [all_expected[k] for k in expected if k in all_expected] self.assertEqual(expected, func(**kwargs)) - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r".*filter non-existent.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.assertEqual([], func(include_faces=True)) - self.check_log(log, "DEBUG", r".*filter non-existent.*") def test_edge_dimension(self): self.assertEqual( @@ -623,9 +618,9 @@ def test_add_connectivities_invalid(self): ) face_node = self.FACE_NODE - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r"Not adding connectivity.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.mesh.add_connectivities(face_node) - self.check_log(log, "DEBUG", r"Not adding connectivity.*") def test_add_coords(self): # ADD coords. @@ -730,9 +725,9 @@ def test_dimension_names(self): default = ugrid.Mesh1DNames("Mesh1d_node", "Mesh1d_edge") self.assertEqual(default, self.mesh.dimension_names()) - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r"Not setting face_dimension.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.mesh.dimension_names("foo", "bar", "baz") - self.check_log(log, "DEBUG", r"Not setting face_dimension.*") self.assertEqual( ugrid.Mesh1DNames("foo", "bar"), self.mesh.dimension_names() ) @@ -751,9 +746,9 @@ def test_edge_dimension_set(self): self.assertEqual("foo", self.mesh.edge_dimension) def test_face_dimension_set(self): - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r"Not setting face_dimension.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.mesh.face_dimension = "foo" - self.check_log(log, "DEBUG", r"Not setting face_dimension.*") self.assertIsNone(self.mesh.face_dimension) def test_node_dimension_set(self): @@ -795,10 +790,12 @@ def test_remove_connectivities(self): {"contains_edge": False, "contains_node": False}, ) + log_regex = r"Ignoring request to remove.*" for kwargs in positive_kwargs: - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + with self.assertLogs( + ugrid.logger, level="DEBUG", msg_regex=log_regex + ): self.mesh.remove_connectivities(**kwargs) - self.check_log(log, "DEBUG", r"Ignoring request to remove.*") self.assertEqual(self.EDGE_NODE, self.mesh.edge_node_connectivity) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: @@ -830,10 +827,12 @@ def test_remove_coords(self): {"attributes": {"test": 2}}, ) + log_regex = r"Ignoring request to remove.*" for kwargs in positive_kwargs: - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + with self.assertLogs( + ugrid.logger, level="DEBUG", msg_regex=log_regex + ): self.mesh.remove_coords(**kwargs) - self.check_log(log, "DEBUG", r"Ignoring request to remove.*") self.assertEqual(self.NODE_LON, self.mesh.node_coords.node_x) for kwargs in negative_kwargs: with self.assertLogs(ugrid.logger, level="DEBUG") as log: @@ -950,9 +949,9 @@ def test_add_connectivities_invalid(self): fake_cf_role = tests.mock.Mock( __class__=ugrid.Connectivity, cf_role="foo" ) - with self.assertLogs(ugrid.logger, level="DEBUG") as log: + log_regex = r"Not adding connectivity.*" + with self.assertLogs(ugrid.logger, level="DEBUG", msg_regex=log_regex): self.mesh.add_connectivities(fake_cf_role) - self.check_log(log, "DEBUG", r"Not adding connectivity.*") def test_add_coords_face(self): # ADD coords. diff --git a/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py b/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py index ca1976398d..8c51dbd130 100644 --- a/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py +++ b/lib/iris/tests/unit/fileformats/netcdf/test_load_cubes.py @@ -314,9 +314,6 @@ def test_missing_mesh(self): _ = list(load_cubes(nc_path)) with PARSE_UGRID_ON_LOAD.context(): - with self.assertLogs(logger, level="DEBUG") as log: + log_regex = r"File does not contain mesh.*" + with self.assertLogs(logger, level="DEBUG", msg_regex=log_regex): _ = list(load_cubes(nc_path)) - rec = log.records[0] - self.assertEqual("DEBUG", rec.levelname) - re_msg = r"File does not contain mesh.*" - self.assertRegex(rec.msg, re_msg)