From: Derrick J. Wippler Date: Thu, 3 Sep 2015 17:07:19 +0000 (-0500) Subject: Hacking log format arg check X-Git-Url: https://review.fuel-infra.org/gitweb?a=commitdiff_plain;h=b7fc72c688ab0eaeb4a85a9af3a26428a94854c5;p=openstack-build%2Fcinder-build.git Hacking log format arg check Added hacking check for log lines that accidently pass a tuple as the second argument when providing format arguments. Change-Id: Ifba23948f9fb49e9f6a1ee7e743aba0cd864c827 Closes-Bug: 1415241 --- diff --git a/HACKING.rst b/HACKING.rst index 2dd920cd5..3b0d67285 100644 --- a/HACKING.rst +++ b/HACKING.rst @@ -26,6 +26,7 @@ Cinder Specific Commandments - [C307] LOG.warn is deprecated. Enforce use of LOG.warning. - [C308] timeutils.isotime() must not be used (deprecated). - [C309] Unit tests should not perform logging. +- [C310] Check for improper use of logging format arguments. General ------- diff --git a/cinder/hacking/checks.py b/cinder/hacking/checks.py index 00ec758d4..ea27decf7 100644 --- a/cinder/hacking/checks.py +++ b/cinder/hacking/checks.py @@ -14,6 +14,7 @@ import ast import re +import six """ Guidelines for writing new hacking checks @@ -202,6 +203,71 @@ class CheckForStrUnicodeExc(BaseASTChecker): super(CheckForStrUnicodeExc, self).generic_visit(node) +class CheckLoggingFormatArgs(BaseASTChecker): + """Check for improper use of logging format arguments. + + LOG.debug("Volume %s caught fire and is at %d degrees C and climbing.", + ('volume1', 500)) + + The format arguments should not be a tuple as it is easy to miss. + + """ + + CHECK_DESC = 'C310 Log method arguments should not be a tuple.' + LOG_METHODS = [ + 'debug', 'info', + 'warn', 'warning', + 'error', 'exception', + 'critical', 'fatal', + 'trace', 'log' + ] + + def _find_name(self, node): + """Return the fully qualified name or a Name or Attribute.""" + if isinstance(node, ast.Name): + return node.id + elif (isinstance(node, ast.Attribute) + and isinstance(node.value, (ast.Name, ast.Attribute))): + method_name = node.attr + obj_name = self._find_name(node.value) + if obj_name is None: + return None + return obj_name + '.' + method_name + elif isinstance(node, six.string_types): + return node + else: # could be Subscript, Call or many more + return None + + def visit_Call(self, node): + """Look for the 'LOG.*' calls.""" + # extract the obj_name and method_name + if isinstance(node.func, ast.Attribute): + obj_name = self._find_name(node.func.value) + if isinstance(node.func.value, ast.Name): + method_name = node.func.attr + elif isinstance(node.func.value, ast.Attribute): + obj_name = self._find_name(node.func.value) + method_name = node.func.attr + else: # could be Subscript, Call or many more + return super(CheckLoggingFormatArgs, self).generic_visit(node) + + # obj must be a logger instance and method must be a log helper + if (obj_name != 'LOG' + or method_name not in self.LOG_METHODS): + return super(CheckLoggingFormatArgs, self).generic_visit(node) + + # the call must have arguments + if not len(node.args): + return super(CheckLoggingFormatArgs, self).generic_visit(node) + + # any argument should not be a tuple + for arg in node.args: + if isinstance(arg, ast.Tuple): + self.add_error(arg) + + return super(CheckLoggingFormatArgs, self).generic_visit(node) + + def validate_log_translations(logical_line, filename): # Translations are not required in the test directory. # This will not catch all instances of violations, just direct @@ -326,6 +392,7 @@ def factory(register): register(no_mutable_default_args) register(check_explicit_underscore_import) register(CheckForStrUnicodeExc) + register(CheckLoggingFormatArgs) register(check_oslo_namespace_imports) register(check_datetime_now) register(check_timeutils_strtime) diff --git a/cinder/tests/unit/test_hacking.py b/cinder/tests/unit/test_hacking.py index b8ba8013b..334d81eaa 100644 --- a/cinder/tests/unit/test_hacking.py +++ b/cinder/tests/unit/test_hacking.py @@ -144,6 +144,37 @@ class HackingTestCase(test.TestCase): def _assert_has_no_errors(self, code, checker, filename=None): self._assert_has_errors(code, checker, filename=filename) + def test_logging_format_args(self): + checker = checks.CheckLoggingFormatArgs + code = """ + import logging + LOG = logging.getLogger() + LOG.info("Message without a second argument.") + LOG.critical("Message with %s arguments.", 'two') + LOG.debug("Volume %s caught fire and is at %d degrees C and" + " climbing.", 'volume1', 500) + """ + self._assert_has_no_errors(code, checker) + + code = """ + import logging + LOG = logging.getLogger() + LOG.{0}("Volume %s caught fire and is at %d degrees C and " + "climbing.", ('volume1', 500)) + """ + for method in checker.LOG_METHODS: + self._assert_has_errors(code.format(method), checker, + expected_errors=[(4, 21, 'C310')]) + + code = """ + import logging + LOG = logging.getLogger() + LOG.log(logging.DEBUG, "Volume %s caught fire and is at %d" + " degrees C and climbing.", ('volume1', 500)) + """ + self._assert_has_errors(code, checker, + expected_errors=[(4, 37, 'C310')]) + def test_str_unicode_exception(self): checker = checks.CheckForStrUnicodeExc diff --git a/cinder/volume/drivers/netapp/eseries/library.py b/cinder/volume/drivers/netapp/eseries/library.py index 8ed9765f5..7d67ab697 100644 --- a/cinder/volume/drivers/netapp/eseries/library.py +++ b/cinder/volume/drivers/netapp/eseries/library.py @@ -1182,8 +1182,8 @@ class NetAppESeriesLibrary(object): try: self._client.delete_volume(vol['volumeRef']) except exception.NetAppDriverException as e: - LOG.debug("Error deleting vol with label %s: %s", - (label, e)) + LOG.debug("Error deleting vol with label %(label)s:" + " %(error)s.", {'label': label, 'error': e}) finally: na_utils.set_safe_attr(self, 'clean_job_running', False)