Add log hacking rules

- [C312] Validate that logs are not translated. [1]
- [H904] Delay string interpolations at logging calls. [2]

[1]https://docs.openstack.org/oslo.i18n/latest/user/usage.html#creating-an-integration-module
[2]https://docs.openstack.org/oslo.i18n/latest/user/guidelines.html#adding-variables-to-log-messages

Change-Id: I0d42c52d90476f2eabbaf0eedfec5d6055117422

tox.ini

@@ -69,9 +69,11 @@ exclude = .venv*,.git,.tox,dist,doc,*lib/python*,*.egg,.update-venv
 # NOTE(flaper87): Our currently max-complexity is 15. Not sure what the ideal complexity
 # for Zaqar should be but lets keep it to the minimum possible.
 max-complexity = 16
+# [H904] Delay string interpolations at logging calls.
+enable-extensions=H904
 
 [hacking]
-import_exceptions = zaqar.i18n
+local-check-factory = zaqar.hacking.checks.factory
 
 [testenv:install-guide]
 commands = sphinx-build -a -E -W -d install-guide/build/doctrees -b html install-guide/source install-guide/build/html

zaqar/api/v2/endpoints.py

@@ -243,7 +243,7 @@ class Endpoints(object):
         try:
             pop_limit = 100
             if "messages" in resource_types:
-                LOG.debug("Purge all messages under queue %s" % queue_name)
+                LOG.debug("Purge all messages under queue %s", queue_name)
                 resp = self._pop_messages(req, queue_name,
                                           project_id, pop_limit)
                 while resp.get_response()['body']['messages']:
@@ -251,7 +251,7 @@ class Endpoints(object):
                                               project_id, pop_limit)
 
             if "subscriptions" in resource_types:
-                LOG.debug("Purge all subscriptions under queue %s" %
+                LOG.debug("Purge all subscriptions under queue %s",
                           queue_name)
                 resp = self._subscription_controller.list(queue_name,
                                                           project=project_id)
@@ -740,7 +740,7 @@ class Endpoints(object):
         claim_id = req._body.get('claim_id')
 
         LOG.debug(u'Claim update - claim: %(claim_id)s, '
-                  u'queue: %(queue_name)s, project:%(project_id)s' %
+                  u'queue: %(queue_name)s, project:%(project_id)s',
                   {'queue_name': queue_name,
                    'project_id': project_id,
                    'claim_id': claim_id})
@@ -787,7 +787,7 @@ class Endpoints(object):
         claim_id = req._body.get('claim_id')
 
         LOG.debug(u'Claim delete - claim: %(claim_id)s, '
-                  u'queue: %(queue_name)s, project: %(project_id)s' %
+                  u'queue: %(queue_name)s, project: %(project_id)s',
                   {'queue_name': queue_name,
                    'project_id': project_id,
                    'claim_id': claim_id})

zaqar/common/api/api.py

@@ -74,7 +74,7 @@ class Api(object):
         try:
             self.validators[action].validate(body)
         except jsonschema.ValidationError as ex:
-            LOG.debug('Schema validation failed. %s.' % str(ex))
+            LOG.debug('Schema validation failed. %s.', str(ex))
             return False
 
         return True

zaqar/common/cli.py

@@ -19,7 +19,6 @@ import sys
 from oslo_config import cfg
 from oslo_log import log as logging
 
-from zaqar.i18n import _
 
 CONF = cfg.CONF
 
@@ -53,7 +52,7 @@ def runnable(func):
             logging.setup(CONF, 'zaqar')
             func()
         except KeyboardInterrupt:
-            LOG.info(_(u'Terminating'))
+            LOG.info(u'Terminating')
         except Exception as ex:
             _fail(1, ex)
 

zaqar/common/decorators.py

@@ -211,7 +211,7 @@ def api_version_manager(version_info):
                             'This version was marked as deprecated in '
                             '%(updated)s. Using it may expose security '
                             'issues, unexpected behavior or damage your '
-                            'data.' % {'version': api_version,
+                            'data.', {'version': api_version,
                                       'updated': api_updated})
             return fn(driver, conf)
         return register_api

zaqar/hacking/checks.py

@@ -0,0 +1,51 @@
+# Copyright (c) 2017 OpenStack Foundation.
+#
+# Licensed under the Apache License, Version 2.0 (the "License"); you may
+# not use this file except in compliance with the License. You may obtain
+# a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+# License for the specific language governing permissions and limitations
+# under the License.
+
+import re
+
+
+_all_log_levels = {'critical', 'error', 'exception', 'info',
+                   'warning', 'debug'}
+
+# Since _Lx() have been removed, we just need to check _()
+_all_hints = {'_'}
+
+_log_translation_hint = re.compile(
+    r".*LOG\.(%(levels)s)\(\s*(%(hints)s)\(" % {
+        'levels': '|'.join(_all_log_levels),
+        'hints': '|'.join(_all_hints),
+    })
+
+
+def no_translate_logs(logical_line):
+    """N537 - Don't translate logs.
+
+    Check for 'LOG.*(_('
+
+    Translators don't provide translations for log messages, and operators
+    asked not to translate them.
+
+    * This check assumes that 'LOG' is a logger.
+
+    :param logical_line: The logical line to check.
+    :returns: None if the logical line passes the check, otherwise a tuple
+    is yielded that contains the offending index in logical line and a
+    message describe the check validation failure.
+    """
+    if _log_translation_hint.match(logical_line):
+        yield (0, "N537: Log messages should not be translated!")
+
+
+def factory(register):
+    register(no_translate_logs)

zaqar/notification/notifier.py

@@ -56,7 +56,7 @@ class NotifierDriver(object):
                     subscribers = self.subscription_controller.list(
                         queue_name, project, marker=marker)
                     for sub in next(subscribers):
-                        LOG.debug("Notifying subscriber %r" % (sub,))
+                        LOG.debug("Notifying subscriber %r", (sub,))
                         s_type = urllib_parse.urlparse(
                             sub['subscriber']).scheme
                         # If the subscriber doesn't contain 'confirmed', it

zaqar/notification/tasks/mailto.py

@@ -102,9 +102,9 @@ class MailtoTask(object):
                 LOG.debug("Send mail successfully: %s", msg.as_string())
         except OSError as err:
             LOG.exception('Failed to create process for sendmail, '
-                          'because %s.' % str(err))
+                          'because %s.', str(err))
         except Exception as exc:
-            LOG.exception('Failed to send email because %s.' % str(exc))
+            LOG.exception('Failed to send email because %s.', str(exc))
 
     def register(self, subscriber, options, ttl, project_id, request_data):
         pass

zaqar/notification/tasks/webhook.py

@@ -41,7 +41,7 @@ class WebhookTask(object):
                               data=data,
                               headers=headers)
         except Exception as e:
-            LOG.exception('webhook task got exception: %s.' % str(e))
+            LOG.exception('webhook task got exception: %s.', str(e))
 
     def register(self, subscriber, options, ttl, project_id, request_data):
         pass

zaqar/storage/pipeline.py

@@ -79,7 +79,7 @@ def _get_storage_pipeline(resource_name, conf, *args, **kwargs):
                                        invoke_on_load=True)
             pipeline.append(mgr.driver)
         except RuntimeError as exc:
-            LOG.warning(_(u'Stage %(stage)s could not be imported: %(ex)s'),
+            LOG.warning(u'Stage %(stage)s could not be imported: %(ex)s',
                         {'stage': ns, 'ex': str(exc)})
             continue
 

zaqar/storage/utils.py

@@ -208,5 +208,5 @@ def can_connect(uri, conf=None):
                                      control_driver=ctrl)
         return driver.is_alive()
     except Exception as exc:
-        LOG.debug('Can\'t connect to: %s \n%s' % (uri, exc))
+        LOG.debug('Can\'t connect to: %s \n%s', (uri, exc))
         return False

zaqar/tests/unit/hacking/test_hacking.py

@@ -0,0 +1,27 @@
+# Copyright (c) 2017 OpenStack Foundation.
+#
+# Licensed under the Apache License, Version 2.0 (the "License"); you may
+# not use this file except in compliance with the License. You may obtain
+# a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+# License for the specific language governing permissions and limitations
+# under the License.
+
+from zaqar.hacking import checks
+from zaqar.tests import base
+
+
+class HackingTestCase(base.TestBase):
+    def test_no_log_translations(self):
+        for log in checks._all_log_levels:
+            for hint in checks._all_hints:
+                bad = 'LOG.%s(%s("Bad"))' % (log, hint)
+                self.assertEqual(1, len(list(checks.no_translate_logs(bad))))
+                # Catch abuses when used with a variable and not a literal
+                bad = 'LOG.%s(%s(msg))' % (log, hint)
+                self.assertEqual(1, len(list(checks.no_translate_logs(bad))))

zaqar/transport/wsgi/v1_1/flavors.py

@@ -57,7 +57,7 @@ class Listing(object):
         :returns: HTTP | 200
         """
 
-        LOG.debug(u'LIST flavors for project_id %s' % project_id)
+        LOG.debug(u'LIST flavors for project_id %s', project_id)
 
         store = {}
         request.get_param('marker', store=store)

zaqar/transport/wsgi/v2_0/flavors.py

@@ -64,7 +64,7 @@ class Listing(object):
         :returns: HTTP | 200
         """
 
-        LOG.debug(u'LIST flavors for project_id %s' % project_id)
+        LOG.debug(u'LIST flavors for project_id %s', project_id)
 
         store = {}
         request.get_param('marker', store=store)

zaqar/transport/wsgi/v2_0/purge.py

@@ -57,7 +57,7 @@ class Resource(object):
         try:
             if "messages" in document['resource_types']:
                 pop_limit = 100
-                LOG.debug("Purge all messages under queue %s" % queue_name)
+                LOG.debug("Purge all messages under queue %s", queue_name)
                 messages = self._message_ctrl.pop(queue_name, pop_limit,
                                                   project=project_id)
                 while messages:
@@ -65,8 +65,7 @@ class Resource(object):
                                                       project=project_id)
 
             if "subscriptions" in document['resource_types']:
-                LOG.debug("Purge all subscriptions under queue %s" %
+                LOG.debug("Purge all subscriptions under queue %s", queue_name)
-                          queue_name)
                 results = self._subscription_ctrl.list(queue_name,
                                                        project=project_id)
                 subscriptions = list(next(results))

zaqar/transport/wsgi/v2_0/queues.py

@@ -150,7 +150,7 @@ class ItemResource(object):
             headers = {'Accept-Patch':
                        ', '.join(sorted(content_types.keys()))}
             msg = _("Accepted media type for PATCH: %s.")
-            LOG.debug(msg % headers)
+            LOG.debug(msg, headers)
             raise wsgi_errors.HTTPUnsupportedMediaType(msg % headers)
 
         if req.content_length: