Fix broken debug logs and modernise string interpolation

Some of the debug logs were not actually outputing the instance;
it was just tagged in the LOF.<type>(...) command.

Also took the opportunity to modernise to '.format()' the string
interpolation to meet current guidelines.

Change-Id: I99c56ff738713140b2af16199e9e58b39bb4e396
Closes-Bug: #1657339
This commit is contained in:
Alex Kavanagh 2018-06-01 15:40:14 +01:00
parent 97cb7ea742
commit 84a7945bca
8 changed files with 131 additions and 126 deletions

View File

@ -123,10 +123,9 @@ def _last_bytes(file_like_object, num):
def _neutron_failed_callback(event_name, instance):
LOG.error('Neutron Reported failure on event '
'%(event)s for instance %(uuid)s',
{'event': event_name, 'uuid': instance.name},
instance=instance)
LOG.error("Neutron Reported failure on event "
"{event} for instance {uuid}"
.format(event=event_name, uuid=instance.name))
if CONF.vif_plugging_is_fatal:
raise exception.VirtualInterfaceCreateException()
@ -140,7 +139,7 @@ def _get_cpu_info():
cpuinfo = {}
out, err = utils.execute('lscpu')
if err:
msg = _('Unable to parse lscpu output.')
msg = _("Unable to parse lscpu output.")
raise exception.NovaException(msg)
cpu = [line.strip('\n') for line in out.splitlines()]
@ -211,7 +210,7 @@ def _get_zpool_info(pool_or_dataset):
pool_or_dataset,
run_as_root=True)
if err:
msg = _('Unable to parse zfs output.')
msg = _("Unable to parse zfs output.")
raise exception.NovaException(msg)
value = int(value.strip())
return value
@ -280,7 +279,7 @@ def _sync_glance_image_to_lxd(client, context, image_ref):
image = IMAGE_API.get(context, image_ref)
if image.get('disk_format') not in ACCEPTABLE_IMAGE_FORMATS:
raise exception.ImageUnacceptable(
image_id=image_ref, reason=_('Bad image format'))
image_id=image_ref, reason=_("Bad image format"))
IMAGE_API.download(context, image_ref, dest_path=image_file)
# It is possible that LXD already have the same image
@ -307,10 +306,10 @@ def _sync_glance_image_to_lxd(client, context, image_ref):
fingerprint = lxdimage_fingerprint()
if client.images.exists(fingerprint):
LOG.info(
'Image with fingerprint %(fingerprint)s already exists'
'but not accessible by alias %(alias)s, add alias',
{'fingerprint': fingerprint, 'alias': image_ref})
LOG.info("Image with fingerprint {fingerprint} already "
"exists but not accessible by alias {alias}, "
"add alias"
.format(fingerprint=fingerprint, alias=image_ref))
lxdimage = client.images.get(fingerprint)
lxdimage.add_alias(image_ref, '')
return True
@ -341,9 +340,9 @@ def _sync_glance_image_to_lxd(client, context, image_ref):
return False
if imagefile_has_metadata(image_file):
LOG.info('Image %(alias)s already has metadata, '
'skipping metadata injection...',
{'alias': image_ref})
LOG.info("Image {alias} already has metadata, "
"skipping metadata injection..."
.format(alias=image_ref))
with open(image_file, 'rb') as image:
image = client.images.create(image, wait=True)
else:
@ -462,7 +461,7 @@ class LXDDriver(driver.ComputeDriver):
try:
self.client = pylxd.Client()
except lxd_exceptions.ClientConnectionFailed as e:
msg = _('Unable to connect to LXD daemon: %s') % e
msg = _("Unable to connect to LXD daemon: {}").format(e)
raise exception.HostNotFound(msg)
self._after_reboot()
@ -543,8 +542,9 @@ class LXDDriver(driver.ComputeDriver):
error_callback=_neutron_failed_callback):
self.plug_vifs(instance, network_info)
except eventlet.timeout.Timeout:
LOG.warn('Timeout waiting for vif plugging callback for '
'instance %(uuid)s', {'uuid': instance['name']})
LOG.warn("Timeout waiting for vif plugging callback for "
"instance {uuid}"
.format(uuid=instance['name']))
if CONF.vif_plugging_is_fatal:
self.destroy(
context, instance, network_info, block_device_info)
@ -637,9 +637,9 @@ class LXDDriver(driver.ComputeDriver):
rescued_container.delete(wait=True)
except lxd_exceptions.LXDAPIException as e:
if e.response.status_code == 404:
LOG.warning('Failed to delete instance. '
'Container does not exist for %(instance)s.',
{'instance': instance.name})
LOG.warning("Failed to delete instance. "
"Container does not exist for {instance}."
.format(instance=instance.name))
else:
raise
finally:
@ -673,9 +673,9 @@ class LXDDriver(driver.ComputeDriver):
self.client.profiles.get(instance.name).delete()
except lxd_exceptions.LXDAPIException as e:
if e.response.status_code == 404:
LOG.warning('Failed to delete instance. '
'Profile does not exist for %(instance)s.',
{'instance': instance.name})
LOG.warning("Failed to delete instance. "
"Profile does not exist for {instance}."
.format(instance=instance.name))
else:
raise
@ -1200,7 +1200,7 @@ class LXDDriver(driver.ComputeDriver):
def check_can_live_migrate_source(self, context, instance,
dest_check_data, block_device_info=None):
if not CONF.lxd.allow_live_migration:
msg = _('Live migration is not enabled.')
msg = _("Live migration is not enabled.")
LOG.error(msg, instance=instance)
raise exception.MigrationPreCheckError(reason=msg)
return dest_check_data
@ -1272,9 +1272,8 @@ class LXDDriver(driver.ComputeDriver):
cdb.make_drive(iso_path)
except processutils.ProcessExecutionError as e:
with excutils.save_and_reraise_exception():
LOG.error('Creating config drive failed with '
'error: %s',
e, instance=instance)
LOG.error("Creating config drive failed with error: {}"
.format(e))
configdrive_dir = os.path.join(
nova.conf.CONF.instances_path, instance.name, 'configdrive')

View File

@ -65,7 +65,7 @@ def _isolated(instance, client):
if 'id_map' in extensions:
return {'security.idmap.isolated': 'True'}
else:
msg = _('Host does not support isolated instances')
msg = _("Host does not support isolated instances")
raise exception.NovaException(msg)
@ -118,7 +118,7 @@ def _root(instance, client, *_):
if 'storage' in extensions:
device['pool'] = CONF.lxd.pool
else:
msg = _('Host does not have storage pool support')
msg = _("Host does not have storage pool support")
raise exception.NovaException(msg)
return {'root': device}
@ -142,7 +142,7 @@ def _ephemeral_storage(instance, client, __, block_info):
if 'storage' in extensions:
device['pool'] = CONF.lxd.pool
else:
msg = _('Host does not have storage pool support')
msg = _("Host does not have storage pool support")
raise exception.NovaException(msg)
devices[ephemeral['virtual_name']] = device
return devices

View File

@ -52,7 +52,7 @@ class LXDAPISession(object):
except Exception as ex:
# notify the compute host that the connection failed
# via an rpc call
LOG.exception('Connection to LXD failed')
LOG.exception("Connection to LXD failed")
payload = dict(ip=CONF.host,
method='_connect',
reason=ex)
@ -70,13 +70,11 @@ class LXDAPISession(object):
:param config: LXD container config as a dict
:param instance: nova instance object
:param host: perform initialization on perfered host
"""
LOG.debug('container_init called for instance', instance=instance)
try:
LOG.info('Creating container %(instance)s with'
' %(image)s', {'instance': instance.name,
'image': instance.image_ref})
LOG.info("Creating container {instance} with {image}"
.format(instance=instance.name,
image=instance.image_ref))
client = self.get_session(host=host)
(state, data) = client.container_init(config)
@ -88,20 +86,17 @@ class LXDAPISession(object):
msg = data.get('err') or data['metadata']
raise exception.NovaException(msg)
LOG.info('Successfully created container %(instance)s with'
' %(image)s', {'instance': instance.name,
'image': instance.image_ref})
LOG.info("Successfully created container {instance} with {image}"
.format(instance=instance.name,
image=instance.image_ref))
except lxd_exceptions.APIError as ex:
msg = _('Failed to communicate with LXD API %(instance)s:'
' %(reason)s') % {'instance': instance.name,
'reason': ex}
msg = (_("Failed to communicate with LXD API {instance}: {reason}")
.format(instance=instance.name, reason=ex))
raise exception.NovaException(msg)
except Exception as ex:
with excutils.save_and_reraise_exception():
LOG.error(
'Failed to create container %(instance)s: %(reason)s',
{'instance': instance.name,
'reason': ex}, instance=instance)
LOG.error("Failed to create container {instance}: {reason}"
.format(instance=instance.name, reason=ex))
#
# Operation methods
@ -113,42 +108,40 @@ class LXDAPISession(object):
:param operation_id: The operation to wait for.
:param instance: nova instace object
"""
LOG.debug('wait_for_container for instance', instance=instance)
LOG.debug("wait_for_container for instance: {}".format(instance))
try:
client = self.get_session(host=host)
if not client.wait_container_operation(operation_id, 200, -1):
msg = _('Container creation timed out')
msg = _("Container creation timed out")
raise exception.NovaException(msg)
except lxd_exceptions.APIError as ex:
msg = _('Failed to communicate with LXD API %(instance)s:'
'%(reason)s') % {'instance': instance.image_ref,
'reason': ex}
msg = _("Failed to communicate with LXD API {instance}: "
"{reason}").format(instance=instance.image_ref,
reason=ex)
LOG.error(msg)
raise exception.NovaException(msg)
except Exception as e:
with excutils.save_and_reraise_exception():
LOG.error('Error from LXD during operation wait'
'%(instance)s: %(reason)s',
{'instance': instance.image_ref, 'reason': e},
instance=instance)
LOG.error("Error from LXD during operation wait "
"{instance}: {reason}"
.format(instance=instance.image_ref, reason=e))
def operation_info(self, operation_id, instance, host=None):
LOG.debug('operation_info called for instance', instance=instance)
LOG.debug("operation_info called for instance {}".format(instance))
try:
client = self.get_session(host=host)
return client.operation_info(operation_id)
except lxd_exceptions.APIError as ex:
msg = _('Failed to communicate with LXD API %(instance)s:'
' %(reason)s') % {'instance': instance.image_ref,
'reason': ex}
msg = _("Failed to communicate with LXD API {instance}:"
" {reason}").format(instance=instance.image_ref,
reason=ex)
LOG.error(msg)
raise exception.NovaException(msg)
except Exception as e:
with excutils.save_and_reraise_exception():
LOG.error('Error from LXD during operation_info '
'%(instance)s: %(reason)s',
{'instance': instance.image_ref, 'reason': e},
instance=instance)
LOG.error("Error from LXD during operation_info "
"{instance}: {reason}"
.format(instance=instance.image_ref, reason=e))
#
# Migrate methods
@ -162,28 +155,26 @@ class LXDAPISession(object):
:return: dictionary of the container keys
"""
LOG.debug('container_migrate called for instance', instance=instance)
LOG.debug("container_migrate called for instance {}".format(instance))
try:
LOG.info('Migrating instance %(instance)s with '
'%(image)s', {'instance': instance_name,
'image': instance.image_ref})
LOG.info("Migrating instance {instance} with {image}"
.format(instance=instance_name,
image=instance.image_ref))
client = self.get_session()
(state, data) = client.container_migrate(instance_name)
LOG.info('Successfully initialized migration for instance '
'%(instance)s with %(image)s',
{'instance': instance.name,
'image': instance.image_ref})
LOG.info("Successfully initialized migration for instance "
"{instance} with {image}"
.format(instance=instance.name,
image=instance.image_ref))
return (state, data)
except lxd_exceptions.APIError as ex:
msg = _('Failed to communicate with LXD API %(instance)s:'
' %(reason)s') % {'instance': instance.name,
'reason': ex}
msg = _("Failed to communicate with LXD API {instance}:"
" {reason}").format(instance=instance.name,
reason=ex)
raise exception.NovaException(msg)
except Exception as ex:
with excutils.save_and_reraise_exception():
LOG.error(
'Failed to migrate container %(instance)s: %('
'reason)s', {'instance': instance.name,
'reason': ex}, instance=instance)
LOG.error("Failed to migrate container {instance}: {reason}"
.format(instance=instance.name, reason=ex))

View File

@ -83,8 +83,8 @@ def attach_ephemeral(client, block_device_info, lxd_config, instance):
cmd = ('mount', '-t', 'ext4', lvm_path, storage_dir)
utils.execute(*cmd, run_as_root=True)
else:
reason = _('Unsupport LXD storage detected. Supported'
' storage drivers are zfs and btrfs.')
reason = _("Unsupport LXD storage detected. Supported"
" storage drivers are zfs and btrfs.")
raise exception.NovaException(reason)
utils.execute(

View File

@ -150,11 +150,12 @@ def _post_plug_wiring(instance, vif):
network infrastructure
"""
LOG.debug("Performing post plug wiring for VIF %s", vif)
LOG.debug("Performing post plug wiring for VIF {}".format(vif))
vif_type = vif['type']
try:
POST_PLUG_WIRING[vif_type](instance, vif)
LOG.debug("Post plug wiring step for VIF {} done".format(vif))
except KeyError:
LOG.debug("No post plug wiring step "
"for vif type: {}".format(vif_type))
@ -190,11 +191,12 @@ def _post_unplug_wiring(instance, vif):
network interfaces assocaited with a lxd container.
"""
LOG.debug("Performing post unplug wiring for VIF %s", vif)
LOG.debug("Performing post unplug wiring for VIF {}".format(vif))
vif_type = vif['type']
try:
POST_UNPLUG_WIRING[vif_type](instance, vif)
LOG.debug("Post unplug wiring for VIF {} done".format(vif))
except KeyError:
LOG.debug("No post unplug wiring step "
"for vif type: {}".format(vif_type))
@ -264,5 +266,5 @@ class LXDGenericVifDriver(object):
try:
network_utils.delete_net_dev(dev)
except processutils.ProcessExecutionError:
LOG.exception("Failed while unplugging vif",
instance=instance)
LOG.exception("Failed while unplugging vif for instance: {}"
.format(instance))

View File

@ -256,8 +256,8 @@ class ScenarioTest(tempest.test.BaseTestCase):
name = data_utils.rand_name(class_name + '-volume-type')
randomized_name = data_utils.rand_name('scenario-type-' + name)
LOG.debug("Creating a volume type: %s on backend %s",
randomized_name, backend_name)
LOG.debug("Creating a volume type: {name} on backend {backend}"
.format(name=randomized_name, backend=backend_name))
extra_specs = {}
if backend_name:
extra_specs = {"volume_backend_name": backend_name}
@ -350,9 +350,10 @@ class ScenarioTest(tempest.test.BaseTestCase):
try:
linux_client.validate_authentication()
except Exception as e:
message = ('Initializing SSH connection to %(ip)s failed. '
'Error: %(error)s' % {'ip': ip_address,
'error': e})
message = ("Initializing SSH connection to {ip} failed. "
"Error: {error}"
.format(ip=ip_address,
error=e))
caller = test_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
@ -399,10 +400,16 @@ class ScenarioTest(tempest.test.BaseTestCase):
img_container_format = CONF.scenario.img_container_format
img_disk_format = CONF.scenario.img_disk_format
img_properties = CONF.scenario.img_properties
LOG.debug("paths: img: %s, container_format: %s, disk_format: %s, "
"properties: %s, ami: %s, ari: %s, aki: %s",
img_path, img_container_format, img_disk_format,
img_properties, ami_img_path, ari_img_path, aki_img_path)
LOG.debug("paths: img: {img}, container_format: {cf}, "
"disk_format: {df}, properties: {props}, ami: {ami}, "
"ari: {ari}, aki: {aki}"
.format(img=img_path,
cf=img_container_format,
df=img_disk_format,
props=img_properties,
ami=ami_img_path,
ari=ari_img_path,
aki=aki_img_path))
try:
image = self._image_create('scenario-img',
img_container_format,
@ -417,13 +424,13 @@ class ScenarioTest(tempest.test.BaseTestCase):
image = self._image_create('scenario-ami', 'ami',
path=ami_img_path,
properties=properties)
LOG.debug("image:%s", image)
LOG.debug("image: {}".format(image))
return image
def _log_console_output(self, servers=None):
if not CONF.compute_feature_enabled.console_output:
LOG.debug('Console output not supported, cannot log')
LOG.debug("Console output not supported, cannot log")
return
if not servers:
servers = self.servers_client.list_servers()
@ -432,16 +439,16 @@ class ScenarioTest(tempest.test.BaseTestCase):
try:
console_output = self.servers_client.get_console_output(
server['id'])['output']
LOG.debug('Console output for %s\nbody=\n%s',
server['id'], console_output)
LOG.debug("Console output for {}\nbody=\n{}"
.format(server['id'], console_output))
except lib_exc.NotFound:
LOG.debug("Server %s disappeared(deleted) while looking "
"for the console log", server['id'])
LOG.debug("Server {} disappeared(deleted) while looking "
"for the console log".format(server['id']))
def _log_net_info(self, exc):
# network debug is called as part of ssh init
if not isinstance(exc, lib_exc.SSHTimeout):
LOG.debug('Network information on a devstack host')
LOG.debug("Network information on a devstack host")
def create_server_snapshot(self, server, name=None):
# Glance client
@ -450,7 +457,8 @@ class ScenarioTest(tempest.test.BaseTestCase):
_images_client = self.compute_images_client
if name is None:
name = data_utils.rand_name(self.__class__.__name__ + 'snapshot')
LOG.debug("Creating a snapshot image for server: %s", server['name'])
LOG.debug("Creating a snapshot image for server: {}"
.format(server['name']))
image = _images_client.create_image(server['id'], name=name)
image_id = image.response['location'].split('images/')[1]
waiters.wait_for_image_status(_image_client, image_id, 'active')
@ -486,8 +494,8 @@ class ScenarioTest(tempest.test.BaseTestCase):
'available')
image_name = snapshot_image['name']
self.assertEqual(name, image_name)
LOG.debug("Created snapshot image %s for server %s",
image_name, server['name'])
LOG.debug("Created snapshot image {} for server {}"
.format(image_name, server['name']))
return snapshot_image
def nova_volume_attach(self, server, volume_to_attach):
@ -517,8 +525,11 @@ class ScenarioTest(tempest.test.BaseTestCase):
rebuild_kwargs = rebuild_kwargs or {}
LOG.debug("Rebuilding server (id: %s, image: %s, preserve eph: %s)",
server_id, image, preserve_ephemeral)
LOG.debug("Rebuilding server (id: {_id}, image: {image}, "
"preserve eph: {ephemeral})"
.format(_id=server_id,
image=image,
ephemeral=preserve_ephemeral))
self.servers_client.rebuild_server(
server_id=server_id, image_ref=image,
preserve_ephemeral=preserve_ephemeral,
@ -550,18 +561,20 @@ class ScenarioTest(tempest.test.BaseTestCase):
return (proc.returncode == 0) == should_succeed
caller = test_utils.find_test_caller()
LOG.debug('%(caller)s begins to ping %(ip)s in %(timeout)s sec and the'
' expected result is %(should_succeed)s', {
'caller': caller, 'ip': ip_address, 'timeout': timeout,
'should_succeed':
'reachable' if should_succeed else 'unreachable'
})
LOG.debug("{caller} begins to ping {ip} in {timeout} sec and the"
" expected result is {should_succeed}"
.format(caller=caller,
ip=ip_address,
timeout=timeout,
should_succeed=('reachable' if should_succeed
else 'unreachable'))
result = test_utils.call_until_true(ping, timeout, 1)
LOG.debug('%(caller)s finishes ping %(ip)s in %(timeout)s sec and the '
'ping result is %(result)s', {
'caller': caller, 'ip': ip_address, 'timeout': timeout,
'result': 'expected' if result else 'unexpected'
})
LOG.debug("{caller} finishes ping {ip} in {timeout} sec and the "
"ping result is {result}"
.format(caller=caller,
ip=ip_address,
timeout=timeout,
result='expected' if result else 'unexpected'))
return result
def check_vm_connectivity(self, ip_address,
@ -599,8 +612,8 @@ class ScenarioTest(tempest.test.BaseTestCase):
msg=None, servers=None, mtu=None):
# The target login is assumed to have been configured for
# key-based authentication by cloud-init.
LOG.debug('checking network connections to IP %s with user: %s',
ip_address, username)
LOG.debug("checking network connections to IP {} with user: {}"
.format(ip_address, username))
try:
self.check_vm_connectivity(ip_address,
username,

View File

@ -65,7 +65,7 @@ class LXDVolumeScenario(manager.ScenarioTest):
def _func():
part = ssh.get_partitions()
LOG.debug("Partitions:%s" % part)
LOG.debug("Partitions: {}".format(part))
return CONF.compute.volume_device_name in part
if not test_utils.call_until_true(_func,

View File

@ -73,8 +73,8 @@ def dump_db(db_driver, db_name, db_url, migration_version, dump_filename):
def diff_files(filename1, filename2):
pipeline = ['diff -U 3 %(filename1)s %(filename2)s'
% {'filename1': filename1, 'filename2': filename2}]
pipeline = ["diff -U 3 {filename1} {filename2}"
.format(filename1=filename1, filename2=filename2)]
# Use colordiff if available
if subprocess.call(['which', 'colordiff']) == 0:
@ -99,8 +99,8 @@ class Mysql(object):
def dump(self, name, dump_filename):
subprocess.check_call(
'mysqldump -u root %(name)s > %(dump_filename)s'
% {'name': name, 'dump_filename': dump_filename},
"mysqldump -u root {name} > {dump_filename}"
.format(name=name, dump_filename=dump_filename),
shell=True)
@ -114,8 +114,8 @@ class Postgresql(object):
def dump(self, name, dump_filename):
subprocess.check_call(
'pg_dump %(name)s > %(dump_filename)s'
% {'name': name, 'dump_filename': dump_filename},
"pg_dump {name} > {dump_filename}"
.format(name=name, dump_filename=dump_filename),
shell=True)
@ -123,7 +123,7 @@ def _get_db_driver_class(db_url):
try:
return globals()[db_url.split('://')[0].capitalize()]
except KeyError:
raise Exception(_("database %s not supported") % db_url)
raise Exception(_("database {] not supported").format(db_url))
# Migrate