diff --git a/HACKING.rst b/HACKING.rst index d0c761d54..0151246cd 100644 --- a/HACKING.rst +++ b/HACKING.rst @@ -16,3 +16,4 @@ Mistral Specific Commandments - [M328] Python 3: do not use dict.iteritems. - [M329] Python 3: do not use dict.iterkeys. - [M330] Python 3: do not use dict.itervalues. +- [M331] String interpolation should be delayed at logging calls. diff --git a/mistral/actions/openstack/action_generator/base.py b/mistral/actions/openstack/action_generator/base.py index 382d9da46..75e049b28 100644 --- a/mistral/actions/openstack/action_generator/base.py +++ b/mistral/actions/openstack/action_generator/base.py @@ -43,8 +43,10 @@ def get_mapping(): path = CONF.openstack_actions_mapping_path mapping_file_path = pkg.resource_filename(package, path) - LOG.info("Processing OpenStack action mapping from file: %s", - mapping_file_path) + LOG.info( + "Processing OpenStack action mapping from file: %s", + mapping_file_path + ) with open(mapping_file_path) as fh: mapping = json.load(fh) @@ -140,8 +142,10 @@ class OpenStackActionGenerator(action_generator.ActionGenerator): try: client_method = class_.get_fake_client_method() except Exception: - LOG.exception("Failed to create action: %s.%s" % - (cls.action_namespace, action_name)) + LOG.exception( + "Failed to create action: %s.%s", + cls.action_namespace, action_name + ) continue arg_list = i_u.get_arg_list_as_str(client_method) diff --git a/mistral/actions/openstack/actions.py b/mistral/actions/openstack/actions.py index 2d2725fb2..f519ab6df 100644 --- a/mistral/actions/openstack/actions.py +++ b/mistral/actions/openstack/actions.py @@ -78,7 +78,7 @@ class NovaAction(base.OpenStackAction): return novaclient.Client def _create_client(self, context): - LOG.debug("Nova action security context: %s" % context) + LOG.debug("Nova action security context: %s", context) return novaclient.Client(2, **self.get_session_and_auth(context)) @@ -96,7 +96,7 @@ class GlanceAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Glance action security context: %s" % context) + LOG.debug("Glance action security context: %s", context) glance_endpoint = self.get_service_endpoint() @@ -121,7 +121,7 @@ class KeystoneAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Keystone action security context: %s" % context) + LOG.debug("Keystone action security context: %s", context) kwargs = self.get_session_and_auth(context) @@ -157,7 +157,7 @@ class CeilometerAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Ceilometer action security context: %s" % context) + LOG.debug("Ceilometer action security context: %s", context) ceilometer_endpoint = self.get_service_endpoint() @@ -188,7 +188,7 @@ class HeatAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Heat action security context: %s" % context) + LOG.debug("Heat action security context: %s", context) heat_endpoint = self.get_service_endpoint() @@ -220,7 +220,7 @@ class NeutronAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Neutron action security context: %s" % context) + LOG.debug("Neutron action security context: %s", context) neutron_endpoint = self.get_service_endpoint() @@ -242,7 +242,7 @@ class CinderAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Cinder action security context: %s" % context) + LOG.debug("Cinder action security context: %s", context) cinder_endpoint = self.get_service_endpoint() @@ -282,7 +282,7 @@ class MistralAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Mistral action security context: %s" % context) + LOG.debug("Mistral action security context: %s", context) session_and_auth = self.get_session_and_auth(context) return self._get_client_class()( @@ -304,7 +304,7 @@ class TroveAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Trove action security context: %s" % context) + LOG.debug("Trove action security context: %s", context) trove_endpoint = self.get_service_endpoint() @@ -341,7 +341,7 @@ class IronicAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Ironic action security context: %s" % context) + LOG.debug("Ironic action security context: %s", context) ironic_endpoint = self.get_service_endpoint() @@ -376,7 +376,7 @@ class BaremetalIntrospectionAction(base.OpenStackAction): return cls._get_client_class()(session=sess) except Exception as e: LOG.warning("There was an error trying to create the " - "ironic-inspector client using a session: %s" % str(e)) + "ironic-inspector client using a session: %s", str(e)) # If it's not possible to establish a keystone session, attempt to # create a client without it. This should fall back to where the # ironic-inspector client tries to get it's own version on the @@ -389,7 +389,7 @@ class BaremetalIntrospectionAction(base.OpenStackAction): def _create_client(self, context): LOG.debug( - "Baremetal introspection action security context: %s" % context) + "Baremetal introspection action security context: %s", context) inspector_endpoint = keystone_utils.get_endpoint_for_project( service_type='baremetal-introspection' @@ -410,7 +410,7 @@ class SwiftAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Swift action security context: %s" % context) + LOG.debug("Swift action security context: %s", context) swift_endpoint = keystone_utils.get_endpoint_for_project('swift') @@ -433,7 +433,7 @@ class ZaqarAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Zaqar action security context: %s" % context) + LOG.debug("Zaqar action security context: %s", context) zaqar_endpoint = keystone_utils.get_endpoint_for_project( service_type='messaging') @@ -538,7 +538,7 @@ class BarbicanAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Barbican action security context: %s" % context) + LOG.debug("Barbican action security context: %s", context) barbican_endpoint = keystone_utils.get_endpoint_for_project('barbican') keystone_endpoint = keystone_utils.get_keystone_endpoint_v2() @@ -644,7 +644,7 @@ class DesignateAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Designate action security context: %s" % context) + LOG.debug("Designate action security context: %s", context) designate_endpoint = self.get_service_endpoint() @@ -680,7 +680,7 @@ class MagnumAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Magnum action security context: %s" % context) + LOG.debug("Magnum action security context: %s", context) keystone_endpoint = keystone_utils.get_keystone_endpoint_v2() auth_url = keystone_endpoint.url @@ -709,7 +709,7 @@ class MuranoAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Murano action security context: %s" % context) + LOG.debug("Murano action security context: %s", context) keystone_endpoint = keystone_utils.get_keystone_endpoint_v2() murano_endpoint = self.get_service_endpoint() @@ -737,7 +737,7 @@ class TackerAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Tacker action security context: %s" % context) + LOG.debug("Tacker action security context: %s", context) keystone_endpoint = keystone_utils.get_keystone_endpoint_v2() tacker_endpoint = self.get_service_endpoint() @@ -765,7 +765,7 @@ class SenlinAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Senlin action security context: %s" % context) + LOG.debug("Senlin action security context: %s", context) keystone_endpoint = keystone_utils.get_keystone_endpoint_v2() senlin_endpoint = self.get_service_endpoint() @@ -793,7 +793,7 @@ class AodhAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Aodh action security context: %s" % context) + LOG.debug("Aodh action security context: %s", context) aodh_endpoint = self.get_service_endpoint() @@ -824,7 +824,7 @@ class GnocchiAction(base.OpenStackAction): def _create_client(self, context): - LOG.debug("Gnocchi action security context: %s" % context) + LOG.debug("Gnocchi action security context: %s", context) gnocchi_endpoint = self.get_service_endpoint() diff --git a/mistral/actions/std_actions.py b/mistral/actions/std_actions.py index a779ccdd8..a7ef13564 100644 --- a/mistral/actions/std_actions.py +++ b/mistral/actions/std_actions.py @@ -45,7 +45,7 @@ class EchoAction(actions.Action): self.output = output def run(self, context): - LOG.info('Running echo action [output=%s]' % self.output) + LOG.info('Running echo action [output=%s]', self.output) return self.output @@ -158,21 +158,23 @@ class HTTPAction(actions.Action): self.verify = verify def run(self, context): - LOG.info("Running HTTP action " - "[url=%s, method=%s, params=%s, body=%s, headers=%s," - " cookies=%s, auth=%s, timeout=%s, allow_redirects=%s," - " proxies=%s, verify=%s]" % - (self.url, - self.method, - self.params, - self.body, - self.headers, - self.cookies, - self.auth, - self.timeout, - self.allow_redirects, - self.proxies, - self.verify)) + LOG.info( + "Running HTTP action " + "[url=%s, method=%s, params=%s, body=%s, headers=%s," + " cookies=%s, auth=%s, timeout=%s, allow_redirects=%s," + " proxies=%s, verify=%s]", + self.url, + self.method, + self.params, + self.body, + self.headers, + self.cookies, + self.auth, + self.timeout, + self.allow_redirects, + self.proxies, + self.verify + ) try: resp = requests.request( @@ -192,7 +194,9 @@ class HTTPAction(actions.Action): raise exc.ActionException("Failed to send HTTP request: %s" % e) LOG.info( - "HTTP action response:\n%s\n%s" % (resp.status_code, resp.content) + "HTTP action response:\n%s\n%s", + resp.status_code, + resp.content ) # TODO(akuznetsova): Need to refactor Mistral serialiser and @@ -295,10 +299,15 @@ class SendEmailAction(actions.Action): self.password = smtp_password def run(self, context): - LOG.info("Sending email message " - "[from=%s, to=%s, subject=%s, using smtp=%s, body=%s...]" % - (self.sender, self.to, self.subject, - self.smtp_server, self.body[:128])) + LOG.info( + "Sending email message " + "[from=%s, to=%s, subject=%s, using smtp=%s, body=%s...]", + self.sender, + self.to, + self.subject, + self.smtp_server, + self.body[:128] + ) message = text.MIMEText(self.body, _charset='utf-8') message['Subject'] = header.Header(self.subject, 'utf-8') @@ -325,10 +334,15 @@ class SendEmailAction(actions.Action): def test(self, context): # Just logging the operation since this action is not supposed # to return a result. - LOG.info("Sending email message " - "[from=%s, to=%s, subject=%s, using smtp=%s, body=%s...]" % - (self.sender, self.to, self.subject, - self.smtp_server, self.body[:128])) + LOG.info( + "Sending email message " + "[from=%s, to=%s, subject=%s, using smtp=%s, body=%s...]", + self.sender, + self.to, + self.subject, + self.smtp_server, + self.body[:128] + ) class SSHAction(actions.Action): @@ -466,7 +480,7 @@ class SleepAction(actions.Action): self._seconds = 0 def run(self, context): - LOG.info('Running sleep action [seconds=%s]' % self._seconds) + LOG.info('Running sleep action [seconds=%s]', self._seconds) time.sleep(self._seconds) @@ -488,8 +502,10 @@ class TestDictAction(actions.Action): def run(self, context): LOG.info( - 'Running test_dict action [size=%s, key_prefix=%s, val=%s]' % - (self.size, self.key_prefix, self.val) + 'Running test_dict action [size=%s, key_prefix=%s, val=%s]', + self.size, + self.key_prefix, + self.val ) res = {} diff --git a/mistral/api/controllers/v2/action_execution.py b/mistral/api/controllers/v2/action_execution.py index b0c8490ec..4612b084f 100644 --- a/mistral/api/controllers/v2/action_execution.py +++ b/mistral/api/controllers/v2/action_execution.py @@ -136,7 +136,10 @@ class ActionExecutionsController(rest.RestController): """ acl.enforce('action_executions:create', context.ctx()) - LOG.info("Create action_execution [action_execution=%s]", action_ex) + LOG.info( + "Create action_execution [action_execution=%s]", + action_ex + ) name = action_ex.name description = action_ex.description or None @@ -172,8 +175,9 @@ class ActionExecutionsController(rest.RestController): acl.enforce('action_executions:update', context.ctx()) LOG.info( - "Update action_execution [id=%s, action_execution=%s]" - % (id, action_ex) + "Update action_execution [id=%s, action_execution=%s]", + id, + action_ex ) output = action_ex.output @@ -274,9 +278,15 @@ class ActionExecutionsController(rest.RestController): description=description ) - LOG.info("Fetch action_executions. marker=%s, limit=%s, " - "sort_keys=%s, sort_dirs=%s, filters=%s", - marker, limit, sort_keys, sort_dirs, filters) + LOG.info( + "Fetch action_executions. marker=%s, limit=%s, " + "sort_keys=%s, sort_dirs=%s, filters=%s", + marker, + limit, + sort_keys, + sort_dirs, + filters + ) return _get_action_executions( marker=marker, @@ -397,9 +407,15 @@ class TasksActionExecutionController(rest.RestController): description=description ) - LOG.info("Fetch action_executions. marker=%s, limit=%s, " - "sort_keys=%s, sort_dirs=%s, filters=%s", - marker, limit, sort_keys, sort_dirs, filters) + LOG.info( + "Fetch action_executions. marker=%s, limit=%s, " + "sort_keys=%s, sort_dirs=%s, filters=%s", + marker, + limit, + sort_keys, + sort_dirs, + filters + ) return _get_action_executions( marker=marker, diff --git a/mistral/api/controllers/v2/cron_trigger.py b/mistral/api/controllers/v2/cron_trigger.py index 84063fa2b..be4d47519 100644 --- a/mistral/api/controllers/v2/cron_trigger.py +++ b/mistral/api/controllers/v2/cron_trigger.py @@ -39,7 +39,7 @@ class CronTriggersController(rest.RestController): """ acl.enforce('cron_triggers:get', context.ctx()) - LOG.info('Fetch cron trigger [name=%s]' % name) + LOG.info('Fetch cron trigger [name=%s]', name) db_model = db_api.get_cron_trigger(name) @@ -58,7 +58,7 @@ class CronTriggersController(rest.RestController): """ acl.enforce('cron_triggers:create', context.ctx()) - LOG.info('Create cron trigger: %s' % cron_trigger) + LOG.info('Create cron trigger: %s', cron_trigger) values = cron_trigger.to_dict() @@ -84,7 +84,7 @@ class CronTriggersController(rest.RestController): """ acl.enforce('cron_triggers:delete', context.ctx()) - LOG.info("Delete cron trigger [name=%s]" % name) + LOG.info("Delete cron trigger [name=%s]", name) triggers.delete_cron_trigger(name) diff --git a/mistral/api/controllers/v2/environment.py b/mistral/api/controllers/v2/environment.py index 15afc7828..a1a1e36a7 100644 --- a/mistral/api/controllers/v2/environment.py +++ b/mistral/api/controllers/v2/environment.py @@ -108,7 +108,7 @@ class EnvironmentController(rest.RestController): """ acl.enforce('environments:get', context.ctx()) - LOG.info("Fetch environment [name=%s]" % name) + LOG.info("Fetch environment [name=%s]", name) db_model = db_api.get_environment(name) @@ -127,7 +127,7 @@ class EnvironmentController(rest.RestController): """ acl.enforce('environments:create', context.ctx()) - LOG.info("Create environment [env=%s]" % env) + LOG.info("Create environment [env=%s]", env) self._validate_environment( json.loads(wsme_pecan.pecan.request.body.decode()), @@ -152,7 +152,7 @@ class EnvironmentController(rest.RestController): 'Name of the environment is not provided.' ) - LOG.info("Update environment [name=%s, env=%s]" % (env.name, env)) + LOG.info("Update environment [name=%s, env=%s]", env.name, env) definition = json.loads(wsme_pecan.pecan.request.body.decode()) definition.pop('name') @@ -175,7 +175,7 @@ class EnvironmentController(rest.RestController): """ acl.enforce('environments:delete', context.ctx()) - LOG.info("Delete environment [name=%s]" % name) + LOG.info("Delete environment [name=%s]", name) db_api.delete_environment(name) diff --git a/mistral/api/controllers/v2/execution.py b/mistral/api/controllers/v2/execution.py index a9fbc6040..a6c1de9f9 100644 --- a/mistral/api/controllers/v2/execution.py +++ b/mistral/api/controllers/v2/execution.py @@ -96,7 +96,7 @@ class ExecutionsController(rest.RestController): """ acl.enforce('executions:update', context.ctx()) - LOG.info('Update execution [id=%s, execution=%s]' % (id, wf_ex)) + LOG.info('Update execution [id=%s, execution=%s]', id, wf_ex) with db_api.transaction(): db_api.ensure_workflow_execution_exists(id) diff --git a/mistral/api/controllers/v2/task.py b/mistral/api/controllers/v2/task.py index cd254c276..a10ecec08 100644 --- a/mistral/api/controllers/v2/task.py +++ b/mistral/api/controllers/v2/task.py @@ -142,7 +142,7 @@ class TasksController(rest.RestController): :param id: UUID of task to retrieve """ acl.enforce('tasks:get', context.ctx()) - LOG.info("Fetch task [id=%s]" % id) + LOG.info("Fetch task [id=%s]", id) with db_api.transaction(): task_ex = db_api.get_task_execution(id) @@ -248,7 +248,7 @@ class TasksController(rest.RestController): """ acl.enforce('tasks:update', context.ctx()) - LOG.info("Update task execution [id=%s, task=%s]" % (id, task)) + LOG.info("Update task execution [id=%s, task=%s]", id, task) with db_api.transaction(): task_ex = db_api.get_task_execution(id) diff --git a/mistral/api/controllers/v2/workbook.py b/mistral/api/controllers/v2/workbook.py index 0218a4a3a..31021266b 100644 --- a/mistral/api/controllers/v2/workbook.py +++ b/mistral/api/controllers/v2/workbook.py @@ -51,7 +51,7 @@ class WorkbooksController(rest.RestController, hooks.HookController): """ acl.enforce('workbooks:get', context.ctx()) - LOG.info("Fetch workbook [name=%s]" % name) + LOG.info("Fetch workbook [name=%s]", name) db_model = db_api.get_workbook(name) @@ -65,7 +65,7 @@ class WorkbooksController(rest.RestController, hooks.HookController): definition = pecan.request.text - LOG.info("Update workbook [definition=%s]" % definition) + LOG.info("Update workbook [definition=%s]", definition) wb_db = workbooks.update_workbook_v2(definition) @@ -79,7 +79,7 @@ class WorkbooksController(rest.RestController, hooks.HookController): definition = pecan.request.text - LOG.info("Create workbook [definition=%s]" % definition) + LOG.info("Create workbook [definition=%s]", definition) wb_db = workbooks.create_workbook_v2(definition) @@ -96,7 +96,7 @@ class WorkbooksController(rest.RestController, hooks.HookController): """ acl.enforce('workbooks:delete', context.ctx()) - LOG.info("Delete workbook [name=%s]" % name) + LOG.info("Delete workbook [name=%s]", name) db_api.delete_workbook(name) diff --git a/mistral/auth/keycloak.py b/mistral/auth/keycloak.py index d3d82d9af..e91f0c7b2 100644 --- a/mistral/auth/keycloak.py +++ b/mistral/auth/keycloak.py @@ -79,7 +79,7 @@ class KeycloakAuthHandler(auth.AuthHandler): resp.raise_for_status() LOG.debug( - "HTTP response from OIDC provider: %s" % + "HTTP response from OIDC provider: %s", pprint.pformat(resp.json()) ) diff --git a/mistral/engine/engine_server.py b/mistral/engine/engine_server.py index 7c36a6c2c..b04f315da 100644 --- a/mistral/engine/engine_server.py +++ b/mistral/engine/engine_server.py @@ -92,9 +92,11 @@ class EngineServer(service_base.MistralService): LOG.info( "Received RPC request 'start_workflow'[workflow_identifier=%s, " - "workflow_input=%s, description=%s, params=%s]" % - (workflow_identifier, utils.cut(workflow_input), - description, params) + "workflow_input=%s, description=%s, params=%s]", + workflow_identifier, + utils.cut(workflow_input), + description, + params ) return self.engine.start_workflow( @@ -117,8 +119,11 @@ class EngineServer(service_base.MistralService): """ LOG.info( "Received RPC request 'start_action'[name=%s, input=%s, " - "description=%s, params=%s]" - % (action_name, utils.cut(action_input), description, params) + "description=%s, params=%s]", + action_name, + utils.cut(action_input), + description, + params ) return self.engine.start_action( @@ -139,7 +144,9 @@ class EngineServer(service_base.MistralService): """ LOG.info( "Received RPC request 'on_action_complete'[action_ex_id=%s, " - "result=%s]" % (action_ex_id, result.cut_repr()) + "result=%s]", + action_ex_id, + result.cut_repr() ) return self.engine.on_action_complete(action_ex_id, result, wf_action) @@ -152,7 +159,7 @@ class EngineServer(service_base.MistralService): :return: Workflow execution. """ LOG.info( - "Received RPC request 'pause_workflow'[execution_id=%s]" % + "Received RPC request 'pause_workflow'[execution_id=%s]", execution_id ) @@ -168,7 +175,7 @@ class EngineServer(service_base.MistralService): :return: Workflow execution. """ LOG.info( - "Received RPC request 'rerun_workflow'[task_ex_id=%s]" % + "Received RPC request 'rerun_workflow'[task_ex_id=%s]", task_ex_id ) @@ -183,7 +190,8 @@ class EngineServer(service_base.MistralService): :return: Workflow execution. """ LOG.info( - "Received RPC request 'resume_workflow'[wf_ex_id=%s]" % wf_ex_id + "Received RPC request 'resume_workflow'[wf_ex_id=%s]", + wf_ex_id ) return self.engine.resume_workflow(wf_ex_id, env) @@ -205,8 +213,10 @@ class EngineServer(service_base.MistralService): """ LOG.info( "Received RPC request 'stop_workflow'[execution_id=%s," - " state=%s, message=%s]" % - (execution_id, state, message) + " state=%s, message=%s]", + execution_id, + state, + message ) return self.engine.stop_workflow(execution_id, state, message) @@ -218,7 +228,7 @@ class EngineServer(service_base.MistralService): :return: Workflow execution. """ LOG.info( - "Received RPC request 'rollback_workflow'[execution_id=%s]" % + "Received RPC request 'rollback_workflow'[execution_id=%s]", execution_id ) diff --git a/mistral/engine/tasks.py b/mistral/engine/tasks.py index a0ce74384..31acbf5da 100644 --- a/mistral/engine/tasks.py +++ b/mistral/engine/tasks.py @@ -284,8 +284,10 @@ class RegularTask(Task): self._create_task_execution() LOG.debug( - 'Starting task [workflow=%s, task=%s, init_state=%s]' % - (self.wf_ex.name, self.task_spec.get_name(), self.task_ex.state) + 'Starting task [workflow=%s, task=%s, init_state=%s]', + self.wf_ex.name, + self.task_spec.get_name(), + self.task_ex.state ) self._before_task_start() diff --git a/mistral/engine/workflows.py b/mistral/engine/workflows.py index eba20a063..1de836624 100644 --- a/mistral/engine/workflows.py +++ b/mistral/engine/workflows.py @@ -220,8 +220,10 @@ class Workflow(object): except Exception as e: LOG.warning( 'Failed to get final context for workflow execution. ' - '[wf_ex_id: %s, wf_name: %s, error: %s]' % - (self.wf_ex.id, self.wf_ex.name, str(e)) + '[wf_ex_id: %s, wf_name: %s, error: %s]', + self.wf_ex.id, + self.wf_ex.name, + str(e) ) return final_context diff --git a/mistral/executors/executor_server.py b/mistral/executors/executor_server.py index 886144921..6fde1ecbc 100644 --- a/mistral/executors/executor_server.py +++ b/mistral/executors/executor_server.py @@ -74,12 +74,11 @@ class ExecutorServer(service_base.MistralService): LOG.info( "Received RPC request 'run_action'[action_ex_id=%s, " - "action_cls_str=%s, action_cls_attrs=%s, params=%s]" % ( - action_ex_id, - action_cls_str, - action_cls_attrs, - utils.cut(params) - ) + "action_cls_str=%s, action_cls_attrs=%s, params=%s]", + action_ex_id, + action_cls_str, + action_cls_attrs, + utils.cut(params) ) redelivered = rpc_ctx.redelivered or False diff --git a/mistral/expressions/__init__.py b/mistral/expressions/__init__.py index 11612155c..d02e1657a 100644 --- a/mistral/expressions/__init__.py +++ b/mistral/expressions/__init__.py @@ -78,8 +78,12 @@ def _evaluate_item(item, context): try: return evaluate(item, context) except AttributeError as e: - LOG.debug("Expression %s is not evaluated, [context=%s]: %s" - % (item, context, e)) + LOG.debug( + "Expression %s is not evaluated, [context=%s]: %s", + item, + context, + e + ) return item else: return evaluate_recursively(item, context) diff --git a/mistral/expressions/jinja_expression.py b/mistral/expressions/jinja_expression.py index 116e2c213..20113b6b1 100644 --- a/mistral/expressions/jinja_expression.py +++ b/mistral/expressions/jinja_expression.py @@ -114,8 +114,10 @@ class InlineJinjaEvaluator(Evaluator): @classmethod def evaluate(cls, expression, data_context): LOG.debug( - "Start to evaluate Jinja expression. [expression='%s', context=%s]" - % (expression, data_context) + "Start to evaluate Jinja expression. " + "[expression='%s', context=%s]", + expression, + data_context ) patterns = cls.find_expression_pattern.findall(expression) @@ -127,8 +129,9 @@ class InlineJinjaEvaluator(Evaluator): result = cls._env.from_string(expression).render(**ctx) LOG.debug( - "Finished evaluation. [expression='%s', result: %s]" % - (expression, result) + "Finished evaluation. [expression='%s', result: %s]", + expression, + result ) return result diff --git a/mistral/expressions/yaql_expression.py b/mistral/expressions/yaql_expression.py index 8f98d99c4..dd2bdb748 100644 --- a/mistral/expressions/yaql_expression.py +++ b/mistral/expressions/yaql_expression.py @@ -84,8 +84,10 @@ class InlineYAQLEvaluator(YAQLEvaluator): @classmethod def evaluate(cls, expression, data_context): LOG.debug( - "Start to evaluate YAQL expression. [expression='%s', context=%s]" - % (expression, data_context) + "Start to evaluate YAQL expression. " + "[expression='%s', context=%s]", + expression, + data_context ) result = expression @@ -102,8 +104,9 @@ class InlineYAQLEvaluator(YAQLEvaluator): result = result.replace(expr, str(evaluated)) LOG.debug( - "Finished evaluation. [expression='%s', result: %s]" % - (expression, result) + "Finished evaluation. [expression='%s', result: %s]", + expression, + result ) return result diff --git a/mistral/hacking/checks.py b/mistral/hacking/checks.py index e1ea14aca..e9d5a1e65 100644 --- a/mistral/hacking/checks.py +++ b/mistral/hacking/checks.py @@ -34,6 +34,9 @@ assert_equal_end_with_none_re = re.compile( r"(.)*assertEqual\((\w|\.|\'|\"|\[|\])+, None\)") assert_equal_start_with_none_re = re.compile( r"(.)*assertEqual\(None, (\w|\.|\'|\"|\[|\])+\)") +log_string_interpolation = re.compile(r".*LOG\.(?:error|warn|warning|info" + r"|critical|exception|debug)" + r"\([^,]*%[^,]*[,)]") def assert_equal_none(logical_line): @@ -122,6 +125,27 @@ def check_python3_no_itervalues(logical_line): yield(0, msg) +def check_delayed_string_interpolation(logical_line, filename, noqa): + """M331: String interpolation should be delayed at logging calls. + + M331: LOG.debug('Example: %s' % 'bad') + Okay: LOG.debug('Example: %s', 'good') + """ + msg = ("M331 String interpolation should be delayed to be " + "handled by the logging code, rather than being done " + "at the point of the logging call. " + "Use ',' instead of '%'.") + + if noqa: + return + + if 'mistral/tests/' in filename: + return + + if log_string_interpolation.match(logical_line): + yield(logical_line.index('%'), msg) + + class BaseASTChecker(ast.NodeVisitor): """Provides a simple framework for writing AST-based checks. @@ -291,3 +315,4 @@ def factory(register): register(check_python3_no_iterkeys) register(check_python3_no_itervalues) register(check_python3_xrange) + register(check_delayed_string_interpolation) diff --git a/mistral/rpc/kombu/kombu_listener.py b/mistral/rpc/kombu/kombu_listener.py index d23b0975b..d5da58f37 100644 --- a/mistral/rpc/kombu/kombu_listener.py +++ b/mistral/rpc/kombu/kombu_listener.py @@ -75,7 +75,7 @@ class KombuRPCListener(ConsumerMixin): try: message.ack() except Exception as e: - LOG.exception("Failed to acknowledge AMQP message: %s" % e) + LOG.exception("Failed to acknowledge AMQP message: %s", e) else: LOG.debug("AMQP message acknowledged.") @@ -103,7 +103,8 @@ class KombuRPCListener(ConsumerMixin): def on_connection_error(self, exc, interval): self.connection = six.next(self._connections) - LOG.debug("Broker connection failed: %s" % exc) - LOG.debug("Sleeping for %s seconds, then retrying connection" % - interval - ) + LOG.debug("Broker connection failed: %s", exc) + LOG.debug( + "Sleeping for %s seconds, then retrying connection", + interval + ) diff --git a/mistral/rpc/kombu/kombu_server.py b/mistral/rpc/kombu/kombu_server.py index eebb1add5..76fb80a73 100644 --- a/mistral/rpc/kombu/kombu_server.py +++ b/mistral/rpc/kombu/kombu_server.py @@ -120,10 +120,11 @@ class KombuRPCServer(rpc_base.RPCServer, kombu_base.Base): self._running.set() self._stopped.clear() - LOG.info("Connected to AMQP at %s:%s" % ( + LOG.info( + "Connected to AMQP at %s:%s", host.hostname, host.port - )) + ) while self.is_running: try: @@ -134,18 +135,20 @@ class KombuRPCServer(rpc_base.RPCServer, kombu_base.Base): self.stop() LOG.info("Server with id='{0}' stopped.".format( - self.server_id)) + self.server_id) + ) return except (socket.error, amqp.exceptions.ConnectionForced) as e: - LOG.debug("Broker connection failed: %s" % e) + LOG.debug("Broker connection failed: %s", e) _retry_connection = True finally: self._stopped.set() if _retry_connection: LOG.debug( - "Sleeping for %s seconds, than retrying connection" % + "Sleeping for %s seconds, than retrying " + "connection", self._sleep_time ) @@ -168,7 +171,7 @@ class KombuRPCServer(rpc_base.RPCServer, kombu_base.Base): try: self._worker.shutdown(wait=True) except AttributeError as e: - LOG.warning("Cannot stop worker in graceful way: %s" % e) + LOG.warning("Cannot stop worker in graceful way: %s", e) def _get_rpc_method(self, method_name): for endpoint in self.endpoints: @@ -209,7 +212,7 @@ class KombuRPCServer(rpc_base.RPCServer, kombu_base.Base): "Got exception while consuming message. Exception would be " "send back to the caller." ) - LOG.debug("Exceptions: %s" % str(e)) + LOG.debug("Exceptions: %s", str(e)) # Wrap exception into another exception for compability with oslo. self.publish_message( @@ -222,8 +225,7 @@ class KombuRPCServer(rpc_base.RPCServer, kombu_base.Base): message.ack() def _on_message(self, request, message): - LOG.debug('Received message %s', - request) + LOG.debug('Received message %s', request) is_async = request.get('async', False) rpc_ctx = request.get('rpc_ctx') diff --git a/mistral/services/action_manager.py b/mistral/services/action_manager.py index 9e49b85d8..e7506cde9 100644 --- a/mistral/services/action_manager.py +++ b/mistral/services/action_manager.py @@ -65,11 +65,11 @@ def register_action_class(name, action_class_str, attributes, } try: - LOG.debug("Registering action in DB: %s" % name) + LOG.debug("Registering action in DB: %s", name) db_api.create_action_definition(values) except exc.DBDuplicateEntryError: - LOG.debug("Action %s already exists in DB." % name) + LOG.debug("Action %s already exists in DB.", name) def _clear_system_action_db(): diff --git a/mistral/services/periodic.py b/mistral/services/periodic.py index 9fc72516a..0bf0608c5 100644 --- a/mistral/services/periodic.py +++ b/mistral/services/periodic.py @@ -36,7 +36,7 @@ class MistralPeriodicTasks(periodic_task.PeriodicTasks): @periodic_task.periodic_task(spacing=1, run_immediately=True) def process_cron_triggers_v2(self, ctx): for trigger in triggers.get_next_cron_triggers(): - LOG.debug("Processing cron trigger: %s" % trigger) + LOG.debug("Processing cron trigger: %s", trigger) try: # Setup admin context before schedule triggers. @@ -45,7 +45,7 @@ class MistralPeriodicTasks(periodic_task.PeriodicTasks): ) auth_ctx.set_ctx(ctx) - LOG.debug("Cron trigger security context: %s" % ctx) + LOG.debug("Cron trigger security context: %s", ctx) # Try to advance the cron trigger next_execution_time and # remaining_executions if relevant. @@ -55,7 +55,8 @@ class MistralPeriodicTasks(periodic_task.PeriodicTasks): if modified: LOG.debug( "Starting workflow '%s' by cron trigger '%s'", - trigger.workflow.name, trigger.name + trigger.workflow.name, + trigger.name ) rpc.get_engine_client().start_workflow( @@ -68,7 +69,8 @@ class MistralPeriodicTasks(periodic_task.PeriodicTasks): except Exception: # Log and continue to next cron trigger. LOG.exception( - "Failed to process cron trigger %s" % str(trigger) + "Failed to process cron trigger %s", + str(trigger) ) finally: auth_ctx.set_ctx(None) diff --git a/mistral/services/security.py b/mistral/services/security.py index 048747b65..f1fb4967c 100644 --- a/mistral/services/security.py +++ b/mistral/services/security.py @@ -98,7 +98,7 @@ def delete_trust(trust_id): try: keystone_client.trusts.delete(trust_id) except Exception as e: - LOG.warning("Failed to delete trust [id=%s]: %s" % (trust_id, e)) + LOG.warning("Failed to delete trust [id=%s]: %s", trust_id, e) def add_trust_id(secure_object_values): diff --git a/mistral/tests/unit/hacking/test_checks.py b/mistral/tests/unit/hacking/test_checks.py index ea7ddbc0c..6d910c457 100644 --- a/mistral/tests/unit/hacking/test_checks.py +++ b/mistral/tests/unit/hacking/test_checks.py @@ -131,6 +131,59 @@ class BaseLoggingCheckTest(base.BaseTest): self.assertEqual(0, len(list(checks.check_python3_no_itervalues( "six.itervalues(ob))")))) + def test_check_delayed_string_interpolation(self): + checker = checks.check_delayed_string_interpolation + code = """ + msg_w = _LW('Test string (%s)') + msg_i = _LI('Test string (%s)') + value = 'test' + + LOG.error(_LE("Test string (%s)") % value) + LOG.warning(msg_w % 'test%string') + LOG.info(msg_i % + "test%string%info") + LOG.critical( + _LC('Test string (%s)') % value, + instance=instance) + LOG.exception(_LE(" 'Test quotation %s' \"Test\"") % 'test') + LOG.debug(' "Test quotation %s" \'Test\'' % "test") + LOG.debug('Tesing %(test)s' % + {'test': ','.join( + ['%s=%s' % (name, value) + for name, value in test.items()])}) + """ + + expected_errors = [(5, 34, 'M331'), (6, 18, 'M331'), (7, 15, 'M331'), + (10, 28, 'M331'), (12, 49, 'M331'), + (13, 40, 'M331'), (14, 28, 'M331')] + self._assert_has_errors(code, checker, expected_errors=expected_errors) + self._assert_has_no_errors( + code, checker, filename='mistral/tests/unit/hacking/test_checks.py' + ) + + code = """ + msg_w = _LW('Test string (%s)') + msg_i = _LI('Test string (%s)') + value = 'test' + + LOG.error(_LE("Test string (%s)"), value) + LOG.error(_LE("Test string (%s)") % value) # noqa + LOG.warn(_LW('Test string (%s)'), + value) + LOG.info(msg_i, + "test%string%info") + LOG.critical( + _LC('Test string (%s)'), value, + instance=instance) + LOG.exception(_LE(" 'Test quotation %s' \"Test\""), 'test') + LOG.debug(' "Test quotation %s" \'Test\'', "test") + LOG.debug('Tesing %(test)s', + {'test': ','.join( + ['%s=%s' % (name, value) + for name, value in test.items()])}) + """ + self._assert_has_no_errors(code, checker) + class TestLoggingWithWarn(BaseLoggingCheckTest): diff --git a/mistral/utils/rest_utils.py b/mistral/utils/rest_utils.py index 195700639..e721afaa1 100644 --- a/mistral/utils/rest_utils.py +++ b/mistral/utils/rest_utils.py @@ -43,7 +43,7 @@ def wrap_wsme_controller_exception(func): except (exc.MistralException, exc.MistralError) as e: pecan.response.translatable_error = e - LOG.error('Error during API call: %s' % str(e)) + LOG.error('Error during API call: %s', str(e)) raise wsme_exc.ClientSideError( msg=six.text_type(e), @@ -64,7 +64,7 @@ def wrap_pecan_controller_exception(func): try: return func(*args, **kwargs) except (exc.MistralException, exc.MistralError) as e: - LOG.error('Error during API call: %s' % str(e)) + LOG.error('Error during API call: %s', str(e)) return webob.Response( status=e.http_code, diff --git a/mistral/utils/ssh_utils.py b/mistral/utils/ssh_utils.py index 2a5d69aa5..f74e99d73 100644 --- a/mistral/utils/ssh_utils.py +++ b/mistral/utils/ssh_utils.py @@ -55,7 +55,7 @@ def _connect(host, username, password=None, pkey=None, proxy=None): if isinstance(pkey, six.string_types): pkey = _to_paramiko_private_key(pkey, password) - LOG.debug('Creating SSH connection to %s' % host) + LOG.debug('Creating SSH connection to %s', host) ssh_client = paramiko.SSHClient() ssh_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) @@ -108,14 +108,14 @@ def execute_command_via_gateway(cmd, host, username, private_key_filename, proxy = None if proxy_command: - LOG.debug('Creating proxy using command: %s' % proxy_command) + LOG.debug('Creating proxy using command: %s', proxy_command) proxy = paramiko.ProxyCommand(proxy_command) _proxy_ssh_client = paramiko.SSHClient() _proxy_ssh_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) - LOG.debug('Connecting to proxy gateway at: %s' % gateway_host) + LOG.debug('Connecting to proxy gateway at: %s', gateway_host) if not gateway_username: gateway_username = username @@ -153,6 +153,6 @@ def execute_command(cmd, host, username, password=None, raise_when_error=True): ssh_client = _connect(host, username, password, private_key_filename) - LOG.debug("Executing command %s" % cmd) + LOG.debug("Executing command %s", cmd) return _execute_command(ssh_client, cmd, get_stderr, raise_when_error) diff --git a/mistral/workflow/base.py b/mistral/workflow/base.py index 77c21d02b..0d8cbdecd 100644 --- a/mistral/workflow/base.py +++ b/mistral/workflow/base.py @@ -148,7 +148,7 @@ class WorkflowController(object): for t_e in task_execs ] - LOG.debug("Commands to rerun workflow tasks: %s" % cmds) + LOG.debug("Commands to rerun workflow tasks: %s", cmds) return cmds diff --git a/mistral/workflow/data_flow.py b/mistral/workflow/data_flow.py index 3175a389f..9d077bde5 100644 --- a/mistral/workflow/data_flow.py +++ b/mistral/workflow/data_flow.py @@ -194,7 +194,8 @@ def publish_variables(task_ex, task_spec): if task_ex.name in expr_ctx: LOG.warning( - 'Shadowing context variable with task name while publishing: %s' % + 'Shadowing context variable with task name while ' + 'publishing: %s', task_ex.name ) diff --git a/mistral/workflow/direct_workflow.py b/mistral/workflow/direct_workflow.py index 2de991502..847e9d519 100644 --- a/mistral/workflow/direct_workflow.py +++ b/mistral/workflow/direct_workflow.py @@ -148,7 +148,7 @@ class DirectWorkflowController(base.WorkflowController): cmds.append(cmd) - LOG.debug("Found commands: %s" % cmds) + LOG.debug("Found commands: %s", cmds) return cmds diff --git a/mistral_tempest_tests/tests/api/v2/test_action_executions.py b/mistral_tempest_tests/tests/api/v2/test_action_executions.py index 4d5ff9af8..edb7b3a55 100644 --- a/mistral_tempest_tests/tests/api/v2/test_action_executions.py +++ b/mistral_tempest_tests/tests/api/v2/test_action_executions.py @@ -46,9 +46,11 @@ class ActionExecutionTestsV2(base.TestCase): try: cls.client.delete_obj('action_executions', action_ex) except Exception as e: - LOG.exception('Exception raised when deleting ' - 'action_executions %s, error message: %s.' - % (action_ex, six.text_type(e))) + LOG.exception( + 'Exception raised when deleting ' + 'action_executions %s, error message: %s.', + action_ex, six.text_type(e) + ) cls.client.action_executions = [] diff --git a/mistral_tempest_tests/tests/scenario/engine/actions/v2/test_ssh_actions.py b/mistral_tempest_tests/tests/scenario/engine/actions/v2/test_ssh_actions.py index 4b998f843..38e32316e 100644 --- a/mistral_tempest_tests/tests/scenario/engine/actions/v2/test_ssh_actions.py +++ b/mistral_tempest_tests/tests/scenario/engine/actions/v2/test_ssh_actions.py @@ -100,7 +100,7 @@ class SSHActionsTestsV2(base.TestCaseAdvanced): def _wait_until_server_up(cls, server_ip, timeout=120, delay=2): seconds_remain = timeout - LOG.info("Waiting server SSH [IP=%s]..." % server_ip) + LOG.info("Waiting server SSH [IP=%s]...", server_ip) while seconds_remain > 0: try: @@ -123,7 +123,7 @@ class SSHActionsTestsV2(base.TestCaseAdvanced): def _wait_until_server_active(cls, server_id, timeout=60, delay=2): seconds_remain = timeout - LOG.info("Waiting server [id=%s]..." % server_id) + LOG.info("Waiting server [id=%s]...", server_id) while seconds_remain > 0: server_info = cls.mgr.servers_client.show_server(server_id) @@ -141,7 +141,7 @@ class SSHActionsTestsV2(base.TestCaseAdvanced): def _wait_until_server_delete(cls, server_id, timeout=60, delay=2): seconds_remain = timeout - LOG.info("Deleting server [id=%s]..." % server_id) + LOG.info("Deleting server [id=%s]...", server_id) while seconds_remain > 0: try: @@ -181,9 +181,7 @@ class SSHActionsTestsV2(base.TestCaseAdvanced): overwrite=True ) - LOG.info( - "Private key saved to %s" % cls.key_dir + cls.key_name - ) + LOG.info("Private key saved to %s", cls.key_dir + cls.key_name) # Create keypair in nova. cls.mgr.keypairs_client.create_keypair(