From 7f17f5010813e1648cba50a8b64edffce67bfd12 Mon Sep 17 00:00:00 2001 From: Takashi Kajinami Date: Wed, 3 Dec 2025 23:33:21 +0900 Subject: [PATCH] Delay string interpolations at logging calls This is a general best practice which brings (slight) performance improvements and also structured logging. Enable the hacking check to enforce it. Change-Id: If32753a456aba1f6cbdf008e90c41df6aeacdddd Signed-off-by: Takashi Kajinami --- heat/api/aws/ec2token.py | 10 +++--- heat/api/cfn/v1/stacks.py | 2 +- heat/api/middleware/version_negotiation.py | 27 +++++++-------- heat/api/openstack/v1/stacks.py | 2 +- heat/common/auth_plugin.py | 2 +- heat/engine/api.py | 4 +-- heat/engine/clients/os/barbican.py | 4 +-- .../os/keystone/heat_keystoneclient.py | 4 +-- heat/engine/resource.py | 2 +- .../resources/openstack/heat/test_resource.py | 4 +-- .../openstack/heat/wait_condition.py | 6 ++-- .../openstack/mistral/external_resource.py | 20 +++++------ .../resources/openstack/trove/instance.py | 33 ++++++++----------- heat/engine/resources/stack_resource.py | 2 +- heat/engine/service.py | 12 +++---- heat/engine/stack.py | 2 +- heat/engine/stack_lock.py | 14 ++++---- heat/objects/stack.py | 2 +- .../framework/message_processor.py | 6 ++-- .../functional/test_autoscaling.py | 8 ++--- tox.ini | 2 +- 21 files changed, 79 insertions(+), 89 deletions(-) diff --git a/heat/api/aws/ec2token.py b/heat/api/aws/ec2token.py index 9d88528606..911cf4e1d0 100644 --- a/heat/api/aws/ec2token.py +++ b/heat/api/aws/ec2token.py @@ -246,18 +246,18 @@ class EC2Token(wsgi.Middleware): if clouds: for cloud in clouds: try: - LOG.debug("Attempt authorize on %s" % cloud) + LOG.debug("Attempt authorize on %s", cloud) return self._authorize(req, cloud) except exception.HeatAPIException as e: - LOG.debug("Authorize failed: %s" % e.__class__) + LOG.debug("Authorize failed: %s", e.__class__) last_failure = e else: for auth_uri in self._conf_get('allowed_auth_uris'): try: - LOG.debug("Attempt authorize on %s" % auth_uri) + LOG.debug("Attempt authorize on %s", auth_uri) return self._authorize(req, auth_uri) except exception.HeatAPIException as e: - LOG.debug("Authorize failed: %s" % e.__class__) + LOG.debug("Authorize failed: %s", e.__class__) last_failure = e raise last_failure or exception.HeatAccessDeniedError() @@ -290,7 +290,7 @@ class EC2Token(wsgi.Middleware): adapter = self._ks_adapters.get(cloud) if not adapter: LOG.error("Ec2Token authorization failed due to missing " - "keystone auth configuration for %s" % cloud) + "keystone auth configuration for %s", cloud) raise exception.HeatInternalFailureError(_('Service ' 'misconfigured')) diff --git a/heat/api/cfn/v1/stacks.py b/heat/api/cfn/v1/stacks.py index 881c43d88b..55195d4e81 100644 --- a/heat/api/cfn/v1/stacks.py +++ b/heat/api/cfn/v1/stacks.py @@ -244,7 +244,7 @@ class StackController(object): return req.params['TemplateBody'] elif 'TemplateUrl' in req.params: url = req.params['TemplateUrl'] - LOG.debug('TemplateUrl %s' % url) + LOG.debug('TemplateUrl %s', url) try: return urlfetch.get(url) except IOError as exc: diff --git a/heat/api/middleware/version_negotiation.py b/heat/api/middleware/version_negotiation.py index 3fc908750c..7bbf8cdd56 100644 --- a/heat/api/middleware/version_negotiation.py +++ b/heat/api/middleware/version_negotiation.py @@ -66,19 +66,20 @@ class VersionNegotiationFilter(wsgi.Middleware): minor_version = req.environ['api.minor_version'] if (major_version == 1 and minor_version == 0): - LOG.debug("Matched versioned URI. " - "Version: %(major_version)d.%(minor_version)d" - % {'major_version': major_version, - 'minor_version': minor_version}) + LOG.debug( + "Matched versioned URI. " + "Version: %(major_version)d.%(minor_version)d", + {'major_version': major_version, + 'minor_version': minor_version}) # Strip the version from the path req.path_info_pop() return None else: LOG.debug("Unknown version in versioned URI: " "%(major_version)d.%(minor_version)d. " - "Returning version choices." - % {'major_version': major_version, - 'minor_version': minor_version}) + "Returning version choices.", + {'major_version': major_version, + 'minor_version': minor_version}) return self.versions_app accept = str(req.accept) @@ -91,16 +92,16 @@ class VersionNegotiationFilter(wsgi.Middleware): minor_version = req.environ['api.minor_version'] if (major_version == 1 and minor_version == 0): LOG.debug("Matched versioned media type. Version: " - "%(major_version)d.%(minor_version)d" - % {'major_version': major_version, - 'minor_version': minor_version}) + "%(major_version)d.%(minor_version)d", + {'major_version': major_version, + 'minor_version': minor_version}) return None else: LOG.debug("Unknown version in accept header: " "%(major_version)d.%(minor_version)d... " - "returning version choices." - % {'major_version': major_version, - 'minor_version': minor_version}) + "returning version choices.", + {'major_version': major_version, + 'minor_version': minor_version}) return self.versions_app else: if req.accept not in ('*/*', ''): diff --git a/heat/api/openstack/v1/stacks.py b/heat/api/openstack/v1/stacks.py index 6f2850e3fd..56eb024c35 100644 --- a/heat/api/openstack/v1/stacks.py +++ b/heat/api/openstack/v1/stacks.py @@ -114,7 +114,7 @@ class InstantiationData(object): elif self.PARAM_TEMPLATE_URL in self.data: url = self.data[self.PARAM_TEMPLATE_URL] - LOG.debug('TemplateUrl %s' % url) + LOG.debug('TemplateUrl %s', url) try: template_data = urlfetch.get(url) except IOError as ex: diff --git a/heat/common/auth_plugin.py b/heat/common/auth_plugin.py index 4052b9b75f..5bd01eac29 100644 --- a/heat/common/auth_plugin.py +++ b/heat/common/auth_plugin.py @@ -32,7 +32,7 @@ def parse_auth_credential_to_dict(cred): try: _cred = json.loads(cred) except ValueError as e: - LOG.error('Failed to parse credential with error: %s' % e) + LOG.error('Failed to parse credential with error: %s', e) raise ValueError('Failed to parse credential, please check your ' 'Stack Credential format.') validate(_cred) diff --git a/heat/engine/api.py b/heat/engine/api.py index 6de9b6f4bc..72d1ded867 100644 --- a/heat/engine/api.py +++ b/heat/engine/api.py @@ -311,8 +311,8 @@ def format_resource_properties(resource): try: return resource.properties[prop] except (KeyError, ValueError): - LOG.exception("Error in fetching property %s of resource %s" % - (prop, resource.name)) + LOG.exception("Error in fetching property %s of resource %s", + prop, resource.name) return None return dict((prop, get_property(prop)) diff --git a/heat/engine/clients/os/barbican.py b/heat/engine/clients/os/barbican.py index ee8c5aca0f..eb28cfc3a2 100644 --- a/heat/engine/clients/os/barbican.py +++ b/heat/engine/clients/os/barbican.py @@ -67,8 +67,8 @@ class BarbicanClientPlugin(client_plugin.ClientPlugin): raise exception.EntityNotFound( entity="Secret", name=secret_ref) - LOG.info('Failed to get Barbican secret from reference %s' % ( - secret_ref)) + LOG.info('Failed to get Barbican secret from reference %s', + secret_ref) raise def get_secret_payload_by_ref(self, secret_ref): diff --git a/heat/engine/clients/os/keystone/heat_keystoneclient.py b/heat/engine/clients/os/keystone/heat_keystoneclient.py index f33bea746a..0610a98216 100644 --- a/heat/engine/clients/os/keystone/heat_keystoneclient.py +++ b/heat/engine/clients/os/keystone/heat_keystoneclient.py @@ -223,8 +223,8 @@ class KsClientWrapper(object): project=trustor_proj_id, impersonation=True, allow_redelegation=allow_redelegation, **role_kw) except ks_exception.NotFound: - LOG.debug("Failed to find roles %s for user %s" - % (role_kw, trustor_user_id)) + LOG.debug("Failed to find roles %s for user %s", + role_kw, trustor_user_id) raise exception.MissingCredentialError( required=_("roles %s") % role_kw) diff --git a/heat/engine/resource.py b/heat/engine/resource.py index 621f562d2e..72bdba55e5 100644 --- a/heat/engine/resource.py +++ b/heat/engine/resource.py @@ -2032,7 +2032,7 @@ class Resource(status.ResourceStatus): while True: count += 1 - LOG.info('delete %(name)s attempt %(attempt)d' % + LOG.info('delete %(name)s attempt %(attempt)d', {'name': str(self), 'attempt': count + 1}) if count: delay = timeutils.retry_backoff_delay(count, diff --git a/heat/engine/resources/openstack/heat/test_resource.py b/heat/engine/resources/openstack/heat/test_resource.py index c7f54783bb..66af52a62b 100644 --- a/heat/engine/resources/openstack/heat/test_resource.py +++ b/heat/engine/resources/openstack/heat/test_resource.py @@ -217,8 +217,8 @@ class TestResource(resource.Resource): obj = getattr(self.client(name=client_name), self.entity) obj.get(entity_id) except Exception as exc: - LOG.debug('%s.%s(%s) %s' % (client_name, self.entity, - entity_id, str(exc))) + LOG.debug('%s.%s(%s) %s', client_name, self.entity, + entity_id, str(exc)) else: # just sleep some more time.sleep(1) diff --git a/heat/engine/resources/openstack/heat/wait_condition.py b/heat/engine/resources/openstack/heat/wait_condition.py index db8ff844e1..c9b2cf624d 100644 --- a/heat/engine/resources/openstack/heat/wait_condition.py +++ b/heat/engine/resources/openstack/heat/wait_condition.py @@ -152,10 +152,8 @@ class HeatWaitCondition(resource.Resource): if key == self.DATA: meta = handle.metadata_get(refresh=True) res = {k: meta[k][handle.DATA] for k in meta} - LOG.debug('%(name)s.GetAtt(%(key)s) == %(res)s' - % {'name': self.name, - 'key': key, - 'res': res}) + LOG.debug('%(name)s.GetAtt(%(key)s) == %(res)s', + {'name': self.name, 'key': key, 'res': res}) return str(jsonutils.dumps(res)) diff --git a/heat/engine/resources/openstack/mistral/external_resource.py b/heat/engine/resources/openstack/mistral/external_resource.py index a38e35b4ed..401e47127c 100644 --- a/heat/engine/resources/openstack/mistral/external_resource.py +++ b/heat/engine/resources/openstack/mistral/external_resource.py @@ -153,9 +153,8 @@ class MistralExternalResource(resource.Resource): raises ResourceUnknownState otherwise. """ execution = self.client().executions.get(execution_id) - LOG.debug('Mistral execution %(id)s is in state ' - '%(state)s' % {'id': execution_id, - 'state': execution.state}) + LOG.debug('Mistral execution %(id)s is in state %(state)s', + {'id': execution_id, 'state': execution.state}) if execution.state in ('IDLE', 'RUNNING', 'PAUSED'): return False, {} @@ -190,9 +189,9 @@ class MistralExternalResource(resource.Resource): workflow_input=jsonutils.dumps(inputs), description=self.properties[self.DESCRIPTION], **action_data[self.PARAMS]) - LOG.debug('Mistral execution %(id)s params set to ' - '%(params)s' % {'id': execution.id, - 'params': action_data[self.PARAMS]}) + LOG.debug('Mistral execution %(id)s params set to %(params)s', + {'id': execution.id, + 'params': action_data[self.PARAMS]}) return execution.id def _check_action(self, action, execution_id): @@ -209,8 +208,8 @@ class MistralExternalResource(resource.Resource): if output.get('resource_id'): rsrc_id = output.get('resource_id') LOG.debug('ExternalResource id set to %(rid)s from Mistral ' - 'execution %(eid)s output' % {'eid': execution_id, - 'rid': rsrc_id}) + 'execution %(eid)s output', + {'eid': execution_id, 'rid': rsrc_id}) self.resource_id_set(str(rsrc_id)[:255]) return success @@ -226,9 +225,8 @@ class MistralExternalResource(resource.Resource): for i in after_props[self.REPLACE_ON_CHANGE]: if old_inputs.get(i) != new_inputs.get(i): LOG.debug('Replacing ExternalResource %(id)s instead of ' - 'updating due to change to input "%(i)s"' % - {"id": self.resource_id, - "i": i}) + 'updating due to change to input "%(i)s"', + {"id": self.resource_id, "i": i}) raise resource.UpdateReplace(self) # honor always_update if found if self.properties[self.ALWAYS_UPDATE]: diff --git a/heat/engine/resources/openstack/trove/instance.py b/heat/engine/resources/openstack/trove/instance.py index 9aa891744f..169f77c7f4 100644 --- a/heat/engine/resources/openstack/trove/instance.py +++ b/heat/engine/resources/openstack/trove/instance.py @@ -480,10 +480,9 @@ class Instance(resource.Resource): _("Unknown"))) if updates: if instance.status != self.ACTIVE: - dmsg = ("Instance is in status %(now)s. Waiting on status" - " %(stat)s") - LOG.debug(dmsg % {"now": instance.status, - "stat": self.ACTIVE}) + LOG.debug("Instance is in status %(now)s. Waiting on status" + " %(stat)s", + {"now": instance.status, "stat": self.ACTIVE}) return False try: return ( @@ -520,17 +519,16 @@ class Instance(resource.Resource): current_flav = str(instance.flavor['id']) new_flav = str(new_flavor) if new_flav != current_flav: - dmsg = "Resizing instance flavor from %(old)s to %(new)s" - LOG.debug(dmsg % {"old": current_flav, "new": new_flav}) + LOG.debug("Resizing instance flavor from %(old)s to %(new)s", + {"old": current_flav, "new": new_flav}) self.client().instances.resize_instance(instance, new_flavor) return False return True def _update_size(self, instance, new_size): if new_size and instance.volume['size'] != new_size: - dmsg = "Resizing instance storage from %(old)s to %(new)s" - LOG.debug(dmsg % {"old": instance.volume['size'], - "new": new_size}) + LOG.debug("Resizing instance storage from %(old)s to %(new)s", + {"old": instance.volume['size'], "new": new_size}) self.client().instances.resize_volume(instance, new_size) return False return True @@ -540,13 +538,12 @@ class Instance(resource.Resource): for db in databases: if db.get("ACTION") == self.CREATE: db.pop("ACTION", None) - dmsg = "Adding new database %(db)s to instance" - LOG.debug(dmsg % {"db": db}) + LOG.debug("Adding new database %(db)s to instance", + {"db": db}) self.client().databases.create(instance, [db]) elif db.get("ACTION") == self.DELETE: - dmsg = ("Deleting existing database %(db)s from " - "instance") - LOG.debug(dmsg % {"db": db['name']}) + LOG.debug("Deleting existing database %(db)s from " + "instance", {"db": db['name']}) self.client().databases.delete(instance, db['name']) return True @@ -558,13 +555,11 @@ class Instance(resource.Resource): usr[self.USER_DATABASES] = dbs if usr.get("ACTION") == self.CREATE: usr.pop("ACTION", None) - dmsg = "Adding new user %(u)s to instance" - LOG.debug(dmsg % {"u": usr}) + LOG.debug("Adding new user %(u)s to instance", {"u": usr}) self.client().users.create(instance, [usr]) elif usr.get("ACTION") == self.DELETE: - dmsg = ("Deleting existing user %(u)s from " - "instance") - LOG.debug(dmsg % {"u": usr['name']}) + LOG.debug("Deleting existing user %(u)s from instance", + {"u": usr['name']}) self.client().users.delete(instance, usr['name']) else: newattrs = {} diff --git a/heat/engine/resources/stack_resource.py b/heat/engine/resources/stack_resource.py index b510423f33..81d42b6fd5 100644 --- a/heat/engine/resources/stack_resource.py +++ b/heat/engine/resources/stack_resource.py @@ -548,7 +548,7 @@ class StackResource(resource.Resource): def _handle_cancel(self): stack_identity = self.nested_identifier() if stack_identity is not None: - LOG.debug('Cancelling %s of %s' % (self.action, self)) + LOG.debug('Cancelling %s of %s', self.action, self) try: self.rpc_client().stack_cancel_update( self.context, diff --git a/heat/engine/service.py b/heat/engine/service.py index e9f13d3cfe..be4e19ff68 100644 --- a/heat/engine/service.py +++ b/heat/engine/service.py @@ -1297,8 +1297,8 @@ class EngineService(service.ServiceBase): stack_identity=stack_identity, message=cancel_message) if cancel_result is None: LOG.debug("Successfully sent %(msg)s message " - "to remote task on engine %(eng)s" % { - 'eng': engine_id, 'msg': cancel_message}) + "to remote task on engine %(eng)s", + {'eng': engine_id, 'msg': cancel_message}) else: raise exception.EventSendFailed(stack_name=current_stack.name, engine_id=engine_id) @@ -1545,9 +1545,9 @@ class EngineService(service.ServiceBase): stack_identity=stack_identity, message=rpc_api.THREAD_CANCEL) if cancel_result is None: LOG.debug("Successfully sent %(msg)s message " - "to remote task on engine %(eng)s" % { - 'eng': acquire_result, - 'msg': rpc_api.THREAD_CANCEL}) + "to remote task on engine %(eng)s", + {'eng': acquire_result, + 'msg': rpc_api.THREAD_CANCEL}) else: raise exception.EventSendFailed(stack_name=stack.name, engine_id=acquire_result) @@ -1945,7 +1945,7 @@ class EngineService(service.ServiceBase): """ def _resource_signal(stack, rsrc, details, need_check): - LOG.debug("signaling resource %s:%s" % (stack.name, rsrc.name)) + LOG.debug("signaling resource %s:%s", stack.name, rsrc.name) needs_metadata_updates = rsrc.signal(details, need_check) if not needs_metadata_updates: diff --git a/heat/engine/stack.py b/heat/engine/stack.py index d0c517411f..ab2f54842f 100644 --- a/heat/engine/stack.py +++ b/heat/engine/stack.py @@ -950,7 +950,7 @@ class Stack(collections.abc.Mapping): dup_names = set(self.parameters) & set(resources) if dup_names: - LOG.debug("Duplicate names %s" % dup_names) + LOG.debug("Duplicate names %s", dup_names) raise exception.StackValidationFailed( message=_("Duplicate names %s") % dup_names) diff --git a/heat/engine/stack_lock.py b/heat/engine/stack_lock.py index e6ae9fba44..ecb7004cd4 100644 --- a/heat/engine/stack_lock.py +++ b/heat/engine/stack_lock.py @@ -59,9 +59,8 @@ class StackLock(object): self.stack_id, self.engine_id) if lock_engine_id is None: - LOG.debug("Engine %(engine)s acquired lock on stack " - "%(stack)s" % {'engine': self.engine_id, - 'stack': self.stack_id}) + LOG.debug("Engine %(engine)s acquired lock on stack %(stack)s", + {'engine': self.engine_id, 'stack': self.stack_id}) return stack = stack_object.Stack.get_by_id(self.context, self.stack_id, @@ -70,8 +69,8 @@ class StackLock(object): if (lock_engine_id == self.engine_id or service_utils.engine_alive(self.context, lock_engine_id)): LOG.debug("Lock on stack %(stack)s is owned by engine " - "%(engine)s" % {'stack': self.stack_id, - 'engine': lock_engine_id}) + "%(engine)s", {'stack': self.stack_id, + 'engine': lock_engine_id}) raise exception.ActionInProgress(stack_name=stack.name, action=stack.action) else: @@ -118,9 +117,8 @@ class StackLock(object): LOG.warning("Lock was already released on stack %s!", self.stack_id) else: - LOG.debug("Engine %(engine)s released lock on stack " - "%(stack)s" % {'engine': self.engine_id, - 'stack': self.stack_id}) + LOG.debug("Engine %(engine)s released lock on stack %(stack)s", + {'engine': self.engine_id, 'stack': self.stack_id}) def __enter__(self): self.acquire() diff --git a/heat/objects/stack.py b/heat/objects/stack.py index a5c781d16d..afdd5434fd 100644 --- a/heat/objects/stack.py +++ b/heat/objects/stack.py @@ -89,7 +89,7 @@ class Stack( return self._raw_template LOG.warning('Loading a raw_template that should have been ' - 'eagerly loaded for stack id %s' % self.id) + 'eagerly loaded for stack id %s', self.id) self._raw_template = raw_template.RawTemplate.get_by_id( self._context, self['raw_template_id']) diff --git a/heat/tests/convergence/framework/message_processor.py b/heat/tests/convergence/framework/message_processor.py index 485e6db3e9..b8f2910523 100644 --- a/heat/tests/convergence/framework/message_processor.py +++ b/heat/tests/convergence/framework/message_processor.py @@ -74,11 +74,11 @@ class MessageProcessor(object): try: method = getattr(self, message.name) except AttributeError: - LOG.error('[%s] Bad message name "%s"' % (self.name, - message.name)) + LOG.error('[%s] Bad message name "%s"', + self.name, message.name) raise else: - LOG.info('[%s] %r' % (self.name, message.data)) + LOG.info('[%s] %r', self.name, message.data) method(message.data) return True diff --git a/heat_integrationtests/functional/test_autoscaling.py b/heat_integrationtests/functional/test_autoscaling.py index 2b34a2b248..abcd871a1e 100644 --- a/heat_integrationtests/functional/test_autoscaling.py +++ b/heat_integrationtests/functional/test_autoscaling.py @@ -627,16 +627,16 @@ outputs: md = self.client.resources.metadata(stack_identifier, 'custom_lb') actual_md = len(md['IPs'].split(',')) if actual_md != expected: - LOG.warning('check_instance_count exp:%d, meta:%s' % (expected, - md['IPs'])) + LOG.warning('check_instance_count exp:%d, meta:%s', + expected, md['IPs']) return False stack = self.client.stacks.get(stack_identifier) inst_list = self._stack_output(stack, 'InstanceList') actual = len(inst_list.split(',')) if actual != expected: - LOG.warning('check_instance_count exp:%d, act:%s' % (expected, - inst_list)) + LOG.warning('check_instance_count exp:%d, act:%s', + expected, inst_list) return actual == expected def test_scaling_meta_update(self): diff --git a/tox.ini b/tox.ini index 1fee482a91..411781b33d 100644 --- a/tox.ini +++ b/tox.ini @@ -85,7 +85,7 @@ show-source = true # W504 line break after binary operator # TODO(tkajinam): Check why Nnnn checks from neutron-lib are enabled ignore = E123,W503,W504,N -enable-extensions = H203,H204,H205,H211,H212 +enable-extensions = H203,H204,H205,H211,H212,H904 exclude=.*,dist,*lib/python*,*egg,build,*convergence/scenarios/* max-complexity=23