openstack/nova
Code Issues Proposed changes

Merge "Cleanup xenapi driver logging messages to include instance"

Browse Source
This commit is contained in:
Jenkins 2012-04-06 16:44:45 +00:00 committed by Gerrit Code Review
commit b573276e00
4 changed files with 140 additions and 152 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

20
nova/tests/test_xenapi.py
View File

@ -895,11 +895,11 @@ class XenAPIMigrateInstance(test.TestCase):
db.migration_get_all_unconfirmed(fake_context, db.migration_get_all_unconfirmed(fake_context,
resize_confirm_window).AndReturn(migrations) resize_confirm_window).AndReturn(migrations)
# Found unconfirmed migrations message # Found unconfirmed migrations message
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
# test success (ACTIVE/RESIZE_VERIFY) # test success (ACTIVE/RESIZE_VERIFY)
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndReturn(instance) instance['uuid']).AndReturn(instance)
conn._vmops.compute_api.confirm_resize(fake_context, conn._vmops.compute_api.confirm_resize(fake_context,
@ -908,7 +908,7 @@ class XenAPIMigrateInstance(test.TestCase):
# test instance that doesn't exist anymore sets migration to # test instance that doesn't exist anymore sets migration to
# error # error
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndRaise(exception.InstanceNotFound) instance['uuid']).AndRaise(exception.InstanceNotFound)
vmops.LOG.warn(mox.IgnoreArg()) vmops.LOG.warn(mox.IgnoreArg())
@ -916,32 +916,32 @@ class XenAPIMigrateInstance(test.TestCase):
# test instance in ERROR/RESIZE_VERIFY sets migration to error # test instance in ERROR/RESIZE_VERIFY sets migration to error
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndReturn(instance) instance['uuid']).AndReturn(instance)
vmops.LOG.warn(mox.IgnoreArg()) vmops.LOG.warn(mox.IgnoreArg(), instance=instance)
db.migration_update(fake_context, 3, {'status': 'error'}) db.migration_update(fake_context, 3, {'status': 'error'})
# test instance in ACTIVE/REBOOTING sets migration to error # test instance in ACTIVE/REBOOTING sets migration to error
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndReturn(instance) instance['uuid']).AndReturn(instance)
vmops.LOG.warn(mox.IgnoreArg()) vmops.LOG.warn(mox.IgnoreArg(), instance=instance)
db.migration_update(fake_context, 4, {'status': 'error'}) db.migration_update(fake_context, 4, {'status': 'error'})
# test confirm_resize raises and doesn't set migration to error # test confirm_resize raises and doesn't set migration to error
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndReturn(instance) instance['uuid']).AndReturn(instance)
conn._vmops.compute_api.confirm_resize(fake_context, conn._vmops.compute_api.confirm_resize(fake_context,
instance).AndRaise(test.TestingException) instance).AndRaise(test.TestingException)
vmops.LOG.error(mox.IgnoreArg()) vmops.LOG.error(mox.IgnoreArg(), instance=instance)
# test succeeds again (ACTIVE/RESIZE_VERIFY) # test succeeds again (ACTIVE/RESIZE_VERIFY)
instance = instances.pop(0) instance = instances.pop(0)
vmops.LOG.info(mox.IgnoreArg()) vmops.LOG.info(mox.IgnoreArg(), mox.IgnoreArg())
db.instance_get_by_uuid(fake_context, db.instance_get_by_uuid(fake_context,
instance['uuid']).AndReturn(instance) instance['uuid']).AndReturn(instance)
conn._vmops.compute_api.confirm_resize(fake_context, conn._vmops.compute_api.confirm_resize(fake_context,

4
nova/utils.py
View File

@ -1715,7 +1715,7 @@ class UndoManager(object):
for undo_func in reversed(self.undo_stack): for undo_func in reversed(self.undo_stack):
undo_func() undo_func()
def rollback_and_reraise(self, msg=None): def rollback_and_reraise(self, msg=None, **kwargs):
"""Rollback a series of actions then re-raise the exception. """Rollback a series of actions then re-raise the exception.
.. note:: (sirp) This should only be called within an .. note:: (sirp) This should only be called within an
@ -1723,6 +1723,6 @@ class UndoManager(object):
""" """
with save_and_reraise_exception(): with save_and_reraise_exception():
if msg: if msg:
LOG.exception(msg) LOG.exception(msg, **kwargs)
self._rollback() self._rollback()

79
nova/virt/xenapi/vm_utils.py
View File

@ -214,10 +214,8 @@ class VMHelper(xenapi.HelperBase):
rec['HVM_boot_params'] = {'order': 'dc'} rec['HVM_boot_params'] = {'order': 'dc'}
rec['HVM_boot_policy'] = 'BIOS order' rec['HVM_boot_policy'] = 'BIOS order'
LOG.debug(_('Created VM %s...'), instance.name)
vm_ref = session.call_xenapi('VM.create', rec) vm_ref = session.call_xenapi('VM.create', rec)
instance_name = instance.name LOG.debug(_('Created VM'), instance=instance)
LOG.debug(_('Created VM %(instance_name)s as %(vm_ref)s.') % locals())
return vm_ref return vm_ref
@classmethod @classmethod
@ -378,8 +376,8 @@ class VMHelper(xenapi.HelperBase):
def create_snapshot(cls, session, instance, vm_ref, label): def create_snapshot(cls, session, instance, vm_ref, label):
"""Creates Snapshot (Template) VM, Snapshot VBD, Snapshot VDI, """Creates Snapshot (Template) VM, Snapshot VBD, Snapshot VDI,
Snapshot VHD""" Snapshot VHD"""
LOG.debug(_("Snapshotting VM %(vm_ref)s with label '%(label)s'...") LOG.debug(_("Snapshotting with label '%(label)s'"), locals(),
% locals()) instance=instance)
vm_vdi_ref, vm_vdi_rec = cls.get_vdi_for_vm_safely(session, vm_ref) vm_vdi_ref, vm_vdi_rec = cls.get_vdi_for_vm_safely(session, vm_ref)
sr_ref = vm_vdi_rec["SR"] sr_ref = vm_vdi_rec["SR"]
@ -391,8 +389,8 @@ class VMHelper(xenapi.HelperBase):
template_vm_ref)[1] template_vm_ref)[1]
template_vdi_uuid = template_vdi_rec["uuid"] template_vdi_uuid = template_vdi_rec["uuid"]
LOG.debug(_('Created snapshot %(template_vm_ref)s from' LOG.debug(_('Created snapshot %(template_vm_ref)s'), locals(),
' VM %(vm_ref)s.') % locals()) instance=instance)
parent_uuid, base_uuid = _wait_for_vhd_coalesce( parent_uuid, base_uuid = _wait_for_vhd_coalesce(
session, instance, sr_ref, vm_vdi_ref, original_parent_uuid) session, instance, sr_ref, vm_vdi_ref, original_parent_uuid)
@ -431,7 +429,7 @@ class VMHelper(xenapi.HelperBase):
# NOTE(sirp): Currently we only support uploading images as VHD, there # NOTE(sirp): Currently we only support uploading images as VHD, there
# is no RAW equivalent (yet) # is no RAW equivalent (yet)
LOG.debug(_("Asking xapi to upload %(vdi_uuids)s as" LOG.debug(_("Asking xapi to upload %(vdi_uuids)s as"
" ID %(image_id)s") % locals()) " ID %(image_id)s"), locals(), instance=instance)
glance_host, glance_port = glance.pick_glance_api_server() glance_host, glance_port = glance.pick_glance_api_server()
@ -582,11 +580,9 @@ class VMHelper(xenapi.HelperBase):
req_type = instance_types.get_instance_type(instance_type_id) req_type = instance_types.get_instance_type(instance_type_id)
req_size = req_type['root_gb'] req_size = req_type['root_gb']
LOG.debug("Creating blank HD of size %(req_size)d gigs" LOG.debug(_("Creating blank HD of size %(req_size)d gigs"), locals())
% locals())
vdi_size = one_gig * req_size vdi_size = one_gig * req_size
LOG.debug("ISO vm create: Looking for the SR")
sr_ref = cls.safe_find_sr(session) sr_ref = cls.safe_find_sr(session)
vdi_ref = cls.create_vdi(session, sr_ref, 'blank HD', vdi_size, False) vdi_ref = cls.create_vdi(session, sr_ref, 'blank HD', vdi_size, False)
@ -751,8 +747,8 @@ class VMHelper(xenapi.HelperBase):
Returns: A list of dictionaries that describe VDIs Returns: A list of dictionaries that describe VDIs
""" """
LOG.debug(_("Asking xapi to fetch vhd image %(image)s") LOG.debug(_("Asking xapi to fetch vhd image %(image)s"), locals(),
% locals()) instance=instance)
sr_ref = cls.safe_find_sr(session) sr_ref = cls.safe_find_sr(session)
vdis = cls._retry_glance_download_vhd(context, session, image) vdis = cls._retry_glance_download_vhd(context, session, image)
@ -762,7 +758,8 @@ class VMHelper(xenapi.HelperBase):
# 'vdi_type' can be 'os' or 'swap' right now. # 'vdi_type' can be 'os' or 'swap' right now.
for vdi in vdis: for vdi in vdis:
LOG.debug(_("xapi 'download_vhd' returned VDI of " LOG.debug(_("xapi 'download_vhd' returned VDI of "
"type '%(vdi_type)s' with UUID '%(vdi_uuid)s'") % vdi) "type '%(vdi_type)s' with UUID '%(vdi_uuid)s'"),
vdi, instance=instance)
cls.scan_sr(session, sr_ref) cls.scan_sr(session, sr_ref)
@ -806,13 +803,12 @@ class VMHelper(xenapi.HelperBase):
allowed_size_bytes = allowed_size_gb * 1024 * 1024 * 1024 allowed_size_bytes = allowed_size_gb * 1024 * 1024 * 1024
LOG.debug(_("image_size_bytes=%(size_bytes)d, allowed_size_bytes=" LOG.debug(_("image_size_bytes=%(size_bytes)d, allowed_size_bytes="
"%(allowed_size_bytes)d") % locals()) "%(allowed_size_bytes)d"), locals(), instance=instance)
if size_bytes > allowed_size_bytes: if size_bytes > allowed_size_bytes:
LOG.info(_("Image size %(size_bytes)d exceeded" LOG.info(_("Image size %(size_bytes)d exceeded instance_type "
" instance_type allowed size " "allowed size %(allowed_size_bytes)d"),
"%(allowed_size_bytes)d") locals(), instance=instance)
% locals())
raise exception.ImageTooLarge() raise exception.ImageTooLarge()
@classmethod @classmethod
@ -828,16 +824,15 @@ class VMHelper(xenapi.HelperBase):
Returns: A single filename if image_type is KERNEL_RAMDISK Returns: A single filename if image_type is KERNEL_RAMDISK
A list of dictionaries that describe VDIs, otherwise A list of dictionaries that describe VDIs, otherwise
""" """
instance_id = instance.id
# FIXME(sirp): Since the Glance plugin seems to be required for the # FIXME(sirp): Since the Glance plugin seems to be required for the
# VHD disk, it may be worth using the plugin for both VHD and RAW and # VHD disk, it may be worth using the plugin for both VHD and RAW and
# DISK restores # DISK restores
LOG.debug(_("Fetching image %(image)s") % locals()) image_type_str = ImageType.to_string(image_type)
LOG.debug(_("Image Type: %s"), ImageType.to_string(image_type)) LOG.debug(_("Fetching image %(image)s, type %(image_type_str)"),
locals(), instance=instance)
if image_type == ImageType.DISK_ISO: if image_type == ImageType.DISK_ISO:
sr_ref = cls.safe_find_iso_sr(session) sr_ref = cls.safe_find_iso_sr(session)
LOG.debug(_("ISO: Found sr possibly containing the ISO image"))
else: else:
sr_ref = cls.safe_find_sr(session) sr_ref = cls.safe_find_sr(session)
@ -846,7 +841,8 @@ class VMHelper(xenapi.HelperBase):
meta, image_file = glance_client.get_image(image_id) meta, image_file = glance_client.get_image(image_id)
virtual_size = int(meta['size']) virtual_size = int(meta['size'])
vdi_size = virtual_size vdi_size = virtual_size
LOG.debug(_("Size for image %(image)s: %(virtual_size)d"), locals()) LOG.debug(_("Size for image %(image)s: %(virtual_size)d"), locals(),
instance=instance)
if image_type == ImageType.DISK: if image_type == ImageType.DISK:
# Make room for MBR. # Make room for MBR.
vdi_size += MBR_SIZE_BYTES vdi_size += MBR_SIZE_BYTES
@ -871,7 +867,8 @@ class VMHelper(xenapi.HelperBase):
if image_type in (ImageType.KERNEL, ImageType.RAMDISK): if image_type in (ImageType.KERNEL, ImageType.RAMDISK):
# We need to invoke a plugin for copying the # We need to invoke a plugin for copying the
# content of the VDI into the proper path. # content of the VDI into the proper path.
LOG.debug(_("Copying VDI %s to /boot/guest on dom0"), vdi_ref) LOG.debug(_("Copying VDI %s to /boot/guest on dom0"),
vdi_ref, instance=instance)
fn = "copy_kernel_vdi" fn = "copy_kernel_vdi"
args = {} args = {}
args['vdi-ref'] = vdi_ref args['vdi-ref'] = vdi_ref
@ -884,7 +881,8 @@ class VMHelper(xenapi.HelperBase):
# Remove the VDI as it is not needed anymore. # Remove the VDI as it is not needed anymore.
cls.destroy_vdi(session, vdi_ref) cls.destroy_vdi(session, vdi_ref)
LOG.debug(_("Kernel/Ramdisk VDI %s destroyed"), vdi_ref) LOG.debug(_("Kernel/Ramdisk VDI %s destroyed"), vdi_ref,
instance=instance)
return [dict(vdi_type=ImageType.to_string(image_type), return [dict(vdi_type=ImageType.to_string(image_type),
vdi_uuid=None, vdi_uuid=None,
file=filename)] file=filename)]
@ -894,8 +892,8 @@ class VMHelper(xenapi.HelperBase):
file=None)] file=None)]
except (cls.XenAPI.Failure, IOError, OSError) as e: except (cls.XenAPI.Failure, IOError, OSError) as e:
# We look for XenAPI and OS failures. # We look for XenAPI and OS failures.
LOG.exception(_("instance %s: Failed to fetch glance image"), LOG.exception(_("Failed to fetch glance image"),
instance_id) instance=instance)
e.args = e.args + ([dict(vdi_type=ImageType. e.args = e.args + ([dict(vdi_type=ImageType.
to_string(image_type), to_string(image_type),
vdi_uuid=vdi_uuid, vdi_uuid=vdi_uuid,
@ -1417,8 +1415,8 @@ def _wait_for_vhd_coalesce(session, instance, sr_ref, vdi_ref,
parent_uuid = get_vhd_parent_uuid(session, vdi_ref) parent_uuid = get_vhd_parent_uuid(session, vdi_ref)
if original_parent_uuid and (parent_uuid != original_parent_uuid): if original_parent_uuid and (parent_uuid != original_parent_uuid):
LOG.debug(_("Parent %(parent_uuid)s doesn't match original parent" LOG.debug(_("Parent %(parent_uuid)s doesn't match original parent"
" %(original_parent_uuid)s, waiting for coalesce...") " %(original_parent_uuid)s, waiting for coalesce..."),
% locals()) locals(), instance=instance)
else: else:
parent_ref = session.call_xenapi("VDI.get_by_uuid", parent_uuid) parent_ref = session.call_xenapi("VDI.get_by_uuid", parent_uuid)
base_uuid = get_vhd_parent_uuid(session, parent_ref) base_uuid = get_vhd_parent_uuid(session, parent_ref)
@ -1565,7 +1563,7 @@ def _write_partition(virtual_size, dev):
primary_last = MBR_SIZE_SECTORS + (virtual_size / SECTOR_SIZE) - 1 primary_last = MBR_SIZE_SECTORS + (virtual_size / SECTOR_SIZE) - 1
LOG.debug(_('Writing partition table %(primary_first)d %(primary_last)d' LOG.debug(_('Writing partition table %(primary_first)d %(primary_last)d'
' to %(dev_path)s...') % locals()) ' to %(dev_path)s...'), locals())
def execute(*cmd, **kwargs): def execute(*cmd, **kwargs):
return utils.execute(*cmd, **kwargs) return utils.execute(*cmd, **kwargs)
@ -1633,7 +1631,7 @@ def _sparse_copy(src_path, dst_path, virtual_size, block_size=4096):
LOG.debug(_("Starting sparse_copy src=%(src_path)s dst=%(dst_path)s " LOG.debug(_("Starting sparse_copy src=%(src_path)s dst=%(dst_path)s "
"virtual_size=%(virtual_size)d block_size=%(block_size)d"), "virtual_size=%(virtual_size)d block_size=%(block_size)d"),
locals()) locals())
# NOTE(sirp): we need read/write access to the devices; since we don't have # NOTE(sirp): we need read/write access to the devices; since we don't have
# the luxury of shelling out to a sudo'd command, we temporarily take # the luxury of shelling out to a sudo'd command, we temporarily take
@ -1714,19 +1712,19 @@ def _find_guest_agent(base_dir, agent_rel_path):
# so manipulation of files in /etc is not # so manipulation of files in /etc is not
# required # required
LOG.info(_('XenServer tools installed in this ' LOG.info(_('XenServer tools installed in this '
'image are capable of network injection. ' 'image are capable of network injection. '
'Networking files will not be' 'Networking files will not be'
'manipulated')) 'manipulated'))
return True return True
xe_daemon_filename = os.path.join(base_dir, xe_daemon_filename = os.path.join(base_dir,
'usr', 'sbin', 'xe-daemon') 'usr', 'sbin', 'xe-daemon')
if os.path.isfile(xe_daemon_filename): if os.path.isfile(xe_daemon_filename):
LOG.info(_('XenServer tools are present ' LOG.info(_('XenServer tools are present '
'in this image but are not capable ' 'in this image but are not capable '
'of network injection')) 'of network injection'))
else: else:
LOG.info(_('XenServer tools are not ' LOG.info(_('XenServer tools are not '
'installed in this image')) 'installed in this image'))
return False return False
@ -1741,8 +1739,7 @@ def _mounted_processing(device, key, net, metadata):
try: try:
# This try block ensures that the umount occurs # This try block ensures that the umount occurs
if not _find_guest_agent(tmpdir, FLAGS.xenapi_agent_path): if not _find_guest_agent(tmpdir, FLAGS.xenapi_agent_path):
LOG.info(_('Manipulating interface files ' LOG.info(_('Manipulating interface files directly'))
'directly'))
# for xenapi, we don't 'inject' admin_password here, # for xenapi, we don't 'inject' admin_password here,
# it's handled at instance startup time # it's handled at instance startup time
disk.inject_data_into_fs(tmpdir, disk.inject_data_into_fs(tmpdir,
@ -1752,7 +1749,7 @@ def _mounted_processing(device, key, net, metadata):
utils.execute('umount', dev_path, run_as_root=True) utils.execute('umount', dev_path, run_as_root=True)
else: else:
LOG.info(_('Failed to mount filesystem (expected for ' LOG.info(_('Failed to mount filesystem (expected for '
'non-linux instances): %s') % err) 'non-linux instances): %s') % err)
def _prepare_injectables(inst, networks_info): def _prepare_injectables(inst, networks_info):

189
nova/virt/xenapi/vmops.py
View File

@ -128,8 +128,8 @@ def make_step_decorator(context, instance):
step_info['current'] += 1 step_info['current'] += 1
progress = round(float(step_info['current']) / progress = round(float(step_info['current']) /
step_info['total'] * 100) step_info['total'] * 100)
LOG.debug(_("Updating instance '%(instance_uuid)s' progress to" LOG.debug(_("Updating progress to %(progress)d"), locals(),
" %(progress)d") % locals()) instance=instance)
db.instance_update(context, instance_uuid, {'progress': progress}) db.instance_update(context, instance_uuid, {'progress': progress})
def step_decorator(f): def step_decorator(f):
@ -230,7 +230,7 @@ class VMOps(object):
if vm_ref is None: if vm_ref is None:
raise Exception(_('Attempted to power on non-existent instance' raise Exception(_('Attempted to power on non-existent instance'
' bad instance id %s') % instance.id) ' bad instance id %s') % instance.id)
LOG.debug(_("Starting instance %s"), instance.name) LOG.debug(_("Starting instance"), instance=instance)
self._session.call_xenapi('VM.start_on', vm_ref, self._session.call_xenapi('VM.start_on', vm_ref,
self._session.get_xenapi_host(), self._session.get_xenapi_host(),
False, False) False, False)
@ -300,7 +300,8 @@ class VMOps(object):
def undo_create_kernel_ramdisk(): def undo_create_kernel_ramdisk():
if kernel_file or ramdisk_file: if kernel_file or ramdisk_file:
LOG.debug(_("Removing kernel/ramdisk files from dom0")) LOG.debug(_("Removing kernel/ramdisk files from dom0"),
instance=instance)
self._destroy_kernel_ramdisk_plugin_call(kernel_file, self._destroy_kernel_ramdisk_plugin_call(kernel_file,
ramdisk_file) ramdisk_file)
undo_mgr.undo_with(undo_create_kernel_ramdisk) undo_mgr.undo_with(undo_create_kernel_ramdisk)
@ -354,10 +355,8 @@ class VMOps(object):
apply_security_group_filters_step(undo_mgr) apply_security_group_filters_step(undo_mgr)
except Exception: except Exception:
instance_uuid = instance['uuid'] msg = _("Failed to spawn, rolling back")
msg = _("Instance %(instance_uuid)s: Failed to spawn, rolling" undo_mgr.rollback_and_reraise(msg=msg, instance=instance)
" back.") % locals()
undo_mgr.rollback_and_reraise(msg=msg)
def spawn_rescue(self, context, instance, image_meta, network_info): def spawn_rescue(self, context, instance, image_meta, network_info):
"""Spawn a rescue instance.""" """Spawn a rescue instance."""
@ -436,15 +435,13 @@ class VMOps(object):
vdis): vdis):
ctx = nova_context.get_admin_context() ctx = nova_context.get_admin_context()
instance_uuid = instance['uuid']
# device 0 reserved for RW disk # device 0 reserved for RW disk
userdevice = 0 userdevice = 0
# DISK_ISO needs two VBDs: the ISO disk and a blank RW disk # DISK_ISO needs two VBDs: the ISO disk and a blank RW disk
if disk_image_type == vm_utils.ImageType.DISK_ISO: if disk_image_type == vm_utils.ImageType.DISK_ISO:
LOG.debug("detected ISO image type, going to create blank VM for " LOG.debug(_("Detected ISO image type, creating blank VM "
"install") "for install"), instance=instance)
cd_vdi_ref = first_vdi_ref cd_vdi_ref = first_vdi_ref
first_vdi_ref = VMHelper.fetch_blank_disk(self._session, first_vdi_ref = VMHelper.fetch_blank_disk(self._session,
@ -462,9 +459,8 @@ class VMOps(object):
userdevice += 1 userdevice += 1
else: else:
if instance.auto_disk_config: if instance.auto_disk_config:
LOG.debug(_("Auto configuring disk for instance" LOG.debug(_("Auto configuring disk, attempting to "
" %(instance_uuid)s, attempting to" "resize partition..."), instance=instance)
" resize partition...") % locals())
instance_type = db.instance_type_get(ctx, instance_type = db.instance_type_get(ctx,
instance.instance_type_id) instance.instance_type_id)
VMHelper.auto_configure_disk(self._session, VMHelper.auto_configure_disk(self._session,
@ -516,40 +512,37 @@ class VMOps(object):
try: try:
injected_files = json.loads(injected_files) injected_files = json.loads(injected_files)
except ValueError: except ValueError:
LOG.exception( LOG.exception(_("Invalid value for injected_files: %r"),
_("Invalid value for injected_files: '%s'") injected_files, instance=instance)
% injected_files)
injected_files = [] injected_files = []
# Inject any files, if specified # Inject any files, if specified
for path, contents in instance.injected_files: for path, contents in instance.injected_files:
LOG.debug(_("Injecting file path: '%s'") % path) LOG.debug(_("Injecting file path: '%s'") % path,
instance=instance)
self.inject_file(instance, path, contents) self.inject_file(instance, path, contents)
admin_password = instance.admin_pass admin_password = instance.admin_pass
# Set admin password, if necessary # Set admin password, if necessary
if admin_password and not skip_set_password: if admin_password and not skip_set_password:
LOG.debug(_("Setting admin password")) LOG.debug(_("Setting admin password"), instance=instance)
self.set_admin_password(instance, admin_password) self.set_admin_password(instance, admin_password)
# Reset network config # Reset network config
LOG.debug(_("Resetting network")) LOG.debug(_("Resetting network"), instance=instance)
self.reset_network(instance, vm_ref) self.reset_network(instance, vm_ref)
# Set VCPU weight # Set VCPU weight
inst_type = db.instance_type_get(ctx, instance.instance_type_id) inst_type = db.instance_type_get(ctx, instance.instance_type_id)
vcpu_weight = inst_type['vcpu_weight'] vcpu_weight = inst_type['vcpu_weight']
if vcpu_weight is not None: if vcpu_weight is not None:
LOG.debug(_("Setting VCPU weight")) LOG.debug(_("Setting VCPU weight"), instance=instance)
self._session.call_xenapi("VM.add_to_VCPUs_params", vm_ref, self._session.call_xenapi("VM.add_to_VCPUs_params", vm_ref,
"weight", str(vcpu_weight)) "weight", str(vcpu_weight))
def _spawn(self, instance, vm_ref): def _spawn(self, instance, vm_ref):
"""Spawn a new instance.""" """Spawn a new instance."""
LOG.debug(_('Starting VM %s...'), vm_ref) LOG.debug(_('Starting VM'), instance=instance)
self._start(instance, vm_ref) self._start(instance, vm_ref)
instance_uuid = instance.uuid
LOG.info(_('Spawning VM %(instance_uuid)s created %(vm_ref)s.')
% locals())
ctx = nova_context.get_admin_context() ctx = nova_context.get_admin_context()
agent_build = db.agent_build_get_by_triple(ctx, 'xen', agent_build = db.agent_build_get_by_triple(ctx, 'xen',
@ -565,7 +558,8 @@ class VMOps(object):
'architecture': instance.architecture}) 'architecture': instance.architecture})
# Wait for boot to finish # Wait for boot to finish
LOG.debug(_('Instance %s: waiting for running'), instance_uuid) LOG.debug(_('Waiting for instance state to become running'),
instance=instance)
expiration = time.time() + FLAGS.xenapi_running_timeout expiration = time.time() + FLAGS.xenapi_running_timeout
while time.time() < expiration: while time.time() < expiration:
state = self.get_info(instance)['state'] state = self.get_info(instance)['state']
@ -574,18 +568,18 @@ class VMOps(object):
greenthread.sleep(0.5) greenthread.sleep(0.5)
LOG.debug(_('Instance %s: running'), instance_uuid)
# Update agent, if necessary # Update agent, if necessary
# This also waits until the agent starts # This also waits until the agent starts
LOG.debug(_("Querying agent version")) LOG.debug(_("Querying agent version"), instance=instance)
version = self.get_agent_version(instance) version = self.get_agent_version(instance)
if version: if version:
LOG.info(_('Instance agent version: %s') % version) LOG.info(_('Instance agent version: %s'), version,
instance=instance)
if (version and agent_build and if (version and agent_build and
cmp_version(version, agent_build['version']) < 0): cmp_version(version, agent_build['version']) < 0):
LOG.info(_('Updating Agent to %s') % agent_build['version']) LOG.info(_('Updating Agent to %s'), agent_build['version'],
instance=instance)
self.agent_update(instance, agent_build['url'], self.agent_update(instance, agent_build['url'],
agent_build['md5hash']) agent_build['md5hash'])
@ -673,15 +667,14 @@ class VMOps(object):
self._destroy(instance, template_vm_ref, self._destroy(instance, template_vm_ref,
shutdown=False, destroy_kernel_ramdisk=False) shutdown=False, destroy_kernel_ramdisk=False)
LOG.debug(_("Finished snapshot and upload for VM %s"), LOG.debug(_("Finished snapshot and upload for VM"),
instance['uuid']) instance=instance)
def _create_snapshot(self, instance): def _create_snapshot(self, instance):
#TODO(sirp): Add quiesce and VSS locking support when Windows support #TODO(sirp): Add quiesce and VSS locking support when Windows support
# is added # is added
instance_uuid = instance.uuid LOG.debug(_("Starting snapshot for VM"), instance=instance)
LOG.debug(_("Starting snapshot for VM %s") % instance_uuid)
vm_ref = VMHelper.lookup(self._session, instance.name) vm_ref = VMHelper.lookup(self._session, instance.name)
label = "%s-snapshot" % instance.name label = "%s-snapshot" % instance.name
@ -690,8 +683,8 @@ class VMOps(object):
self._session, instance, vm_ref, label) self._session, instance, vm_ref, label)
return template_vm_ref, template_vdi_uuids return template_vm_ref, template_vdi_uuids
except self.XenAPI.Failure, exc: except self.XenAPI.Failure, exc:
LOG.error(_("Unable to Snapshot instance %(instance_uuid)s: " LOG.error(_("Unable to Snapshot instance: %(exc)s"), locals(),
"%(exc)s") % locals()) instance=instance)
raise raise
def _migrate_vhd(self, instance, vdi_uuid, dest, sr_path): def _migrate_vhd(self, instance, vdi_uuid, dest, sr_path):
@ -726,8 +719,8 @@ class VMOps(object):
# has been streamed to the destination host. # has been streamed to the destination host.
progress = round(float(step) / total_steps * 100) progress = round(float(step) / total_steps * 100)
instance_uuid = instance['uuid'] instance_uuid = instance['uuid']
LOG.debug(_("Updating instance '%(instance_uuid)s' progress to" LOG.debug(_("Updating progress to %(progress)d"), locals(),
" %(progress)d") % locals()) instance=instance)
db.instance_update(context, instance_uuid, {'progress': progress}) db.instance_update(context, instance_uuid, {'progress': progress})
def migrate_disk_and_power_off(self, context, instance, dest, def migrate_disk_and_power_off(self, context, instance, dest,
@ -775,7 +768,8 @@ class VMOps(object):
new_gb = instance_type['root_gb'] new_gb = instance_type['root_gb']
LOG.debug(_("Resizing down VDI %(cow_uuid)s from " LOG.debug(_("Resizing down VDI %(cow_uuid)s from "
"%(old_gb)dGB to %(new_gb)dGB") % locals()) "%(old_gb)dGB to %(new_gb)dGB"), locals(),
instance=instance)
# 2. Power down the instance before resizing # 2. Power down the instance before resizing
self._shutdown(instance, vm_ref, hard=False) self._shutdown(instance, vm_ref, hard=False)
@ -897,14 +891,14 @@ class VMOps(object):
if virtual_size < new_disk_size: if virtual_size < new_disk_size:
# Resize up. Simple VDI resize will do the trick # Resize up. Simple VDI resize will do the trick
LOG.debug(_("Resizing up VDI %(vdi_uuid)s from %(old_gb)dGB to " LOG.debug(_("Resizing up VDI %(vdi_uuid)s from %(old_gb)dGB to "
"%(new_gb)dGB") % locals()) "%(new_gb)dGB"), locals(), instance=instance)
if self._session.product_version[0] > 5: if self._session.product_version[0] > 5:
resize_func_name = 'VDI.resize' resize_func_name = 'VDI.resize'
else: else:
resize_func_name = 'VDI.resize_online' resize_func_name = 'VDI.resize_online'
self._session.call_xenapi(resize_func_name, vdi_ref, self._session.call_xenapi(resize_func_name, vdi_ref,
str(new_disk_size)) str(new_disk_size))
LOG.debug(_("Resize instance %s complete") % (instance.uuid)) LOG.debug(_("Resize complete"), instance=instance)
def reboot(self, instance, reboot_type): def reboot(self, instance, reboot_type):
"""Reboot VM instance.""" """Reboot VM instance."""
@ -931,8 +925,8 @@ class VMOps(object):
# Send the encrypted password # Send the encrypted password
resp = self._make_agent_call('version', instance) resp = self._make_agent_call('version', instance)
if resp['returncode'] != '0': if resp['returncode'] != '0':
LOG.error(_('Failed to query agent version: %(resp)r') % LOG.error(_('Failed to query agent version: %(resp)r'),
locals()) locals(), instance=instance)
return None return None
# Some old versions of the Windows agent have a trailing \\r\\n # Some old versions of the Windows agent have a trailing \\r\\n
# (ie CRLF escaped) for some reason. Strip that off. # (ie CRLF escaped) for some reason. Strip that off.
@ -951,10 +945,9 @@ class VMOps(object):
vm_rec = self._session.call_xenapi("VM.get_record", vm_ref) vm_rec = self._session.call_xenapi("VM.get_record", vm_ref)
if vm_rec['domid'] != domid: if vm_rec['domid'] != domid:
LOG.info(_('domid changed from %(olddomid)s to ' newdomid = vm_rec['domid']
'%(newdomid)s') % { LOG.info(_('domid changed from %(domid)s to %(newdomid)s'),
'olddomid': domid, locals(), instance=instance)
'newdomid': vm_rec['domid']})
domid = vm_rec['domid'] domid = vm_rec['domid']
return None return None
@ -966,7 +959,8 @@ class VMOps(object):
args = {'url': url, 'md5sum': md5sum} args = {'url': url, 'md5sum': md5sum}
resp = self._make_agent_call('agentupdate', instance, args) resp = self._make_agent_call('agentupdate', instance, args)
if resp['returncode'] != '0': if resp['returncode'] != '0':
LOG.error(_('Failed to update agent: %(resp)r') % locals()) LOG.error(_('Failed to update agent: %(resp)r'), locals(),
instance=instance)
return None return None
return resp['message'] return resp['message']
@ -987,7 +981,7 @@ class VMOps(object):
# Successful return code from key_init is 'D0' # Successful return code from key_init is 'D0'
if resp['returncode'] != 'D0': if resp['returncode'] != 'D0':
msg = _('Failed to exchange keys: %(resp)r') % locals() msg = _('Failed to exchange keys: %(resp)r') % locals()
LOG.error(msg) LOG.error(msg, instance=instance)
raise Exception(msg) raise Exception(msg)
# Some old versions of the Windows agent have a trailing \\r\\n # Some old versions of the Windows agent have a trailing \\r\\n
# (ie CRLF escaped) for some reason. Strip that off. # (ie CRLF escaped) for some reason. Strip that off.
@ -1002,7 +996,7 @@ class VMOps(object):
# Successful return code from password is '0' # Successful return code from password is '0'
if resp['returncode'] != '0': if resp['returncode'] != '0':
msg = _('Failed to update password: %(resp)r') % locals() msg = _('Failed to update password: %(resp)r') % locals()
LOG.error(msg) LOG.error(msg, instance=instance)
raise Exception(msg) raise Exception(msg)
return resp['message'] return resp['message']
@ -1026,21 +1020,20 @@ class VMOps(object):
# will be raised with the appropriate message. # will be raised with the appropriate message.
resp = self._make_agent_call('inject_file', instance, args) resp = self._make_agent_call('inject_file', instance, args)
if resp['returncode'] != '0': if resp['returncode'] != '0':
LOG.error(_('Failed to inject file: %(resp)r') % locals()) LOG.error(_('Failed to inject file: %(resp)r'), locals(),
instance=instance)
return None return None
return resp['message'] return resp['message']
def _shutdown(self, instance, vm_ref, hard=True): def _shutdown(self, instance, vm_ref, hard=True):
"""Shutdown an instance.""" """Shutdown an instance."""
instance_uuid = instance.uuid
state = self.get_info(instance)['state'] state = self.get_info(instance)['state']
if state == power_state.SHUTDOWN: if state == power_state.SHUTDOWN:
LOG.warn(_("VM %(instance_uuid)s already halted," LOG.warn(_("VM already halted, skipping shutdown..."),
"skipping shutdown...") % locals()) instance=instance)
return return
LOG.debug(_("Shutting down VM for Instance %(instance_uuid)s") LOG.debug(_("Shutting down VM"), instance=instance)
% locals())
try: try:
task = None task = None
if hard: if hard:
@ -1101,8 +1094,8 @@ class VMOps(object):
instance_uuid = instance['uuid'] instance_uuid = instance['uuid']
if not instance.kernel_id and not instance.ramdisk_id: if not instance.kernel_id and not instance.ramdisk_id:
# 1. No kernel or ramdisk # 1. No kernel or ramdisk
LOG.debug(_("Instance %(instance_uuid)s using RAW or VHD, " LOG.debug(_("Using RAW or VHD, skipping kernel and ramdisk "
"skipping kernel and ramdisk deletion") % locals()) "deletion"), instance=instance)
return return
if not (instance.kernel_id and instance.ramdisk_id): if not (instance.kernel_id and instance.ramdisk_id):
@ -1115,17 +1108,17 @@ class VMOps(object):
vm_ref) vm_ref)
self._destroy_kernel_ramdisk_plugin_call(kernel, ramdisk) self._destroy_kernel_ramdisk_plugin_call(kernel, ramdisk)
LOG.debug(_("kernel/ramdisk files removed")) LOG.debug(_("kernel/ramdisk files removed"), instance=instance)
def _destroy_vm(self, instance, vm_ref): def _destroy_vm(self, instance, vm_ref):
"""Destroys a VM record.""" """Destroys a VM record."""
instance_uuid = instance['uuid']
try: try:
self._session.call_xenapi('VM.destroy', vm_ref) self._session.call_xenapi('VM.destroy', vm_ref)
except self.XenAPI.Failure, exc: except self.XenAPI.Failure, exc:
LOG.exception(exc) LOG.exception(exc)
return
LOG.debug(_("Instance %(instance_uuid)s VM destroyed") % locals()) LOG.debug(_("VM destroyed"), instance=instance)
def _destroy_rescue_instance(self, rescue_vm_ref, original_vm_ref): def _destroy_rescue_instance(self, rescue_vm_ref, original_vm_ref):
"""Destroy a rescue instance.""" """Destroy a rescue instance."""
@ -1151,8 +1144,7 @@ class VMOps(object):
destroy_* methods are internal. destroy_* methods are internal.
""" """
instance_uuid = instance['uuid'] LOG.info(_("Destroying VM"), instance=instance)
LOG.info(_("Destroying VM for Instance %(instance_uuid)s") % locals())
vm_ref = VMHelper.lookup(self._session, instance.name) vm_ref = VMHelper.lookup(self._session, instance.name)
@ -1174,7 +1166,8 @@ class VMOps(object):
""" """
if vm_ref is None: if vm_ref is None:
LOG.warning(_("VM is not present, skipping destroy...")) LOG.warning(_("VM is not present, skipping destroy..."),
instance=instance)
return return
is_snapshot = VMHelper.is_snapshot(self._session, vm_ref) is_snapshot = VMHelper.is_snapshot(self._session, vm_ref)
if shutdown: if shutdown:
@ -1301,10 +1294,10 @@ class VMOps(object):
if instances_info["instance_count"] > 0: if instances_info["instance_count"] > 0:
LOG.info(_("Found %(instance_count)d hung reboots " LOG.info(_("Found %(instance_count)d hung reboots "
"older than %(timeout)d seconds") % instances_info) "older than %(timeout)d seconds") % instances_info)
for instance in instances: for instance in instances:
LOG.info(_("Automatically hard rebooting %d"), instance.id) LOG.info(_("Automatically hard rebooting"), instance=instance)
self.compute_api.reboot(ctxt, instance, "HARD") self.compute_api.reboot(ctxt, instance, "HARD")
def poll_rescued_instances(self, timeout): def poll_rescued_instances(self, timeout):
@ -1363,14 +1356,14 @@ class VMOps(object):
if migrations_info["migration_count"] > 0: if migrations_info["migration_count"] > 0:
LOG.info(_("Found %(migration_count)d unconfirmed migrations " LOG.info(_("Found %(migration_count)d unconfirmed migrations "
"older than %(confirm_window)d seconds") % migrations_info) "older than %(confirm_window)d seconds"),
migrations_info)
def _set_migration_to_error(migration_id, reason): def _set_migration_to_error(migration_id, reason, **kwargs):
msg = _("Setting migration %(migration_id)s to error: " msg = _("Setting migration %(migration_id)s to error: "
"%(reason)s") % locals() "%(reason)s") % locals()
LOG.warn(msg) LOG.warn(msg, **kwargs)
db.migration_update( db.migration_update(ctxt, migration_id, {'status': 'error'})
ctxt, migration_id, {'status': 'error'})
for migration in migrations: for migration in migrations:
# NOTE(comstud): Yield to other greenthreads. Putting this # NOTE(comstud): Yield to other greenthreads. Putting this
@ -1378,9 +1371,8 @@ class VMOps(object):
greenthread.sleep(0) greenthread.sleep(0)
migration_id = migration['id'] migration_id = migration['id']
instance_uuid = migration['instance_uuid'] instance_uuid = migration['instance_uuid']
msg = _("Automatically confirming migration %(migration_id)s " LOG.info(_("Automatically confirming migration %(migration_id)s "
"for instance %(instance_uuid)s") "for instance %(instance_uuid)s"), locals())
LOG.info(msg % locals())
try: try:
instance = db.instance_get_by_uuid(ctxt, instance_uuid) instance = db.instance_get_by_uuid(ctxt, instance_uuid)
except exception.InstanceNotFound: except exception.InstanceNotFound:
@ -1388,21 +1380,22 @@ class VMOps(object):
_set_migration_to_error(migration_id, reason % locals()) _set_migration_to_error(migration_id, reason % locals())
continue continue
if instance['vm_state'] == vm_states.ERROR: if instance['vm_state'] == vm_states.ERROR:
reason = _("Instance %(instance_uuid)s in ERROR state") reason = _("In ERROR state")
_set_migration_to_error(migration_id, reason % locals()) _set_migration_to_error(migration_id, reason % locals(),
instance=instance)
continue continue
if instance['task_state'] != task_states.RESIZE_VERIFY: if instance['task_state'] != task_states.RESIZE_VERIFY:
task_state = instance['task_state'] task_state = instance['task_state']
reason = _("Instance %(instance_uuid)s in %(task_state)s " reason = _("In %(task_state)s task_state, not RESIZE_VERIFY")
"task_state, not RESIZE_VERIFY.") _set_migration_to_error(migration_id, reason % locals(),
_set_migration_to_error(migration_id, reason % locals()) instance=instance)
continue continue
try: try:
self.compute_api.confirm_resize(ctxt, instance) self.compute_api.confirm_resize(ctxt, instance)
except Exception, e: except Exception, e:
msg = _("Error auto-confirming resize for instance " msg = _("Error auto-confirming resize: %(e)s. "
"%(instance_uuid)s: %(e)s. Will retry later.") "Will retry later.")
LOG.error(msg % locals()) LOG.error(msg % locals(), instance=instance)
def get_info(self, instance): def get_info(self, instance):
"""Return data about VM instance.""" """Return data about VM instance."""
@ -1473,7 +1466,7 @@ class VMOps(object):
self._session.call_xenapi("VM.get_record", vm_ref) self._session.call_xenapi("VM.get_record", vm_ref)
else: else:
vm_ref = VMHelper.lookup(self._session, instance.name) vm_ref = VMHelper.lookup(self._session, instance.name)
LOG.debug(_("injecting network info to xs for vm: |%s|"), vm_ref) LOG.debug(_("Injecting network info to xenstore"), instance=instance)
for (network, info) in network_info: for (network, info) in network_info:
location = 'vm-data/networking/%s' % info['mac'].replace(':', '') location = 'vm-data/networking/%s' % info['mac'].replace(':', '')
@ -1487,7 +1480,7 @@ class VMOps(object):
def create_vifs(self, vm_ref, instance, network_info): def create_vifs(self, vm_ref, instance, network_info):
"""Creates vifs for an instance.""" """Creates vifs for an instance."""
LOG.debug(_("creating vif(s) for vm: |%s|"), vm_ref) LOG.debug(_("Creating vifs"), instance=instance)
# this function raises if vm_ref is not a vm_opaque_ref # this function raises if vm_ref is not a vm_opaque_ref
self._session.call_xenapi("VM.get_record", vm_ref) self._session.call_xenapi("VM.get_record", vm_ref)
@ -1496,11 +1489,11 @@ class VMOps(object):
vif_rec = self.vif_driver.plug(instance, network, info, vif_rec = self.vif_driver.plug(instance, network, info,
vm_ref=vm_ref, device=device) vm_ref=vm_ref, device=device)
network_ref = vif_rec['network'] network_ref = vif_rec['network']
LOG.debug(_('Creating VIF for VM %(vm_ref)s,' LOG.debug(_('Creating VIF for network %(network_ref)s'),
' network %(network_ref)s.') % locals()) locals(), instance=instance)
vif_ref = self._session.call_xenapi('VIF.create', vif_rec) vif_ref = self._session.call_xenapi('VIF.create', vif_rec)
LOG.debug(_('Created VIF %(vif_ref)s for VM %(vm_ref)s,' LOG.debug(_('Created VIF %(vif_ref)s, network %(network_ref)s'),
' network %(network_ref)s.') % locals()) locals(), instance=instance)
def plug_vifs(self, instance, network_info): def plug_vifs(self, instance, network_info):
"""Set up VIF networking on the host.""" """Set up VIF networking on the host."""
@ -1524,7 +1517,7 @@ class VMOps(object):
# NOTE(jk0): Windows hostnames can only be <= 15 chars. # NOTE(jk0): Windows hostnames can only be <= 15 chars.
hostname = hostname[:15] hostname = hostname[:15]
LOG.debug(_("injecting hostname to xs for vm: |%s|"), vm_ref) LOG.debug(_("Injecting hostname to xenstore"), instance=instance)
self.add_to_param_xenstore(vm_ref, 'vm-data/hostname', hostname) self.add_to_param_xenstore(vm_ref, 'vm-data/hostname', hostname)
def write_to_xenstore(self, instance, path, value, vm_ref=None): def write_to_xenstore(self, instance, path, value, vm_ref=None):
@ -1549,10 +1542,9 @@ class VMOps(object):
try: try:
return json.loads(ret) return json.loads(ret)
except TypeError: except TypeError:
instance_uuid = instance['uuid']
LOG.error(_('The agent call to %(method)s returned an invalid' LOG.error(_('The agent call to %(method)s returned an invalid'
' response: %(ret)r. VM id=%(instance_uuid)s;' ' response: %(ret)r. path=%(path)s; args=%(args)r'),
' path=%(path)s; args=%(args)r') % locals()) locals(), instance=instance)
return {'returncode': 'error', return {'returncode': 'error',
'message': 'unable to deserialize response'} 'message': 'unable to deserialize response'}
@ -1562,7 +1554,6 @@ class VMOps(object):
Abstracts out the process of calling a method of a xenapi plugin. Abstracts out the process of calling a method of a xenapi plugin.
Any errors raised by the plugin will in turn raise a RuntimeError here. Any errors raised by the plugin will in turn raise a RuntimeError here.
""" """
instance_uuid = instance['uuid']
vm_ref = vm_ref or self._get_vm_opaque_ref(instance) vm_ref = vm_ref or self._get_vm_opaque_ref(instance)
vm_rec = self._session.call_xenapi("VM.get_record", vm_ref) vm_rec = self._session.call_xenapi("VM.get_record", vm_ref)
args = {'dom_id': vm_rec['domid']} args = {'dom_id': vm_rec['domid']}
@ -1573,16 +1564,16 @@ class VMOps(object):
err_msg = e.details[-1].splitlines()[-1] err_msg = e.details[-1].splitlines()[-1]
if 'TIMEOUT:' in err_msg: if 'TIMEOUT:' in err_msg:
LOG.error(_('TIMEOUT: The call to %(method)s timed out. ' LOG.error(_('TIMEOUT: The call to %(method)s timed out. '
'VM id=%(instance_uuid)s; args=%(args)r') % locals()) 'args=%(args)r'), locals(), instance=instance)
return {'returncode': 'timeout', 'message': err_msg} return {'returncode': 'timeout', 'message': err_msg}
elif 'NOT IMPLEMENTED:' in err_msg: elif 'NOT IMPLEMENTED:' in err_msg:
LOG.error(_('NOT IMPLEMENTED: The call to %(method)s is not' LOG.error(_('NOT IMPLEMENTED: The call to %(method)s is not'
' supported by the agent. VM id=%(instance_uuid)s;' ' supported by the agent. args=%(args)r'),
' args=%(args)r') % locals()) locals(), instance=instance)
return {'returncode': 'notimplemented', 'message': err_msg} return {'returncode': 'notimplemented', 'message': err_msg}
else: else:
LOG.error(_('The call to %(method)s returned an error: %(e)s. ' LOG.error(_('The call to %(method)s returned an error: %(e)s. '
'VM id=%(instance_uuid)s; args=%(args)r') % locals()) 'args=%(args)r'), locals(), instance=instance)
return {'returncode': 'error', 'message': err_msg} return {'returncode': 'error', 'message': err_msg}
return None return None