diff --git a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/LibvirtComputingResource.java b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/LibvirtComputingResource.java index ba175c445731..37db67257f98 100644 --- a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/LibvirtComputingResource.java +++ b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/LibvirtComputingResource.java @@ -4588,12 +4588,19 @@ public List> cleanVMSnapshotMetadata(Domain dm) s_logger.debug("Cleaning the metadata of vm snapshots of vm " + dm.getName()); List> vmsnapshots = new ArrayList>(); if (dm.snapshotNum() == 0) { + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("VM [%s] does not have any snapshots. Skipping cleanup of snapshots for this VM.", dm.getName())); + } return vmsnapshots; } String currentSnapshotName = null; try { DomainSnapshot snapshotCurrent = dm.snapshotCurrent(); String snapshotXML = snapshotCurrent.getXMLDesc(); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Current snapshot of VM [%s] has the following XML: [%s].", dm.getName(), snapshotXML)); + } + snapshotCurrent.free(); DocumentBuilder builder; try { @@ -4605,25 +4612,25 @@ public List> cleanVMSnapshotMetadata(Domain dm) Element rootElement = doc.getDocumentElement(); currentSnapshotName = getTagValue("name", rootElement); - } catch (ParserConfigurationException e) { - s_logger.debug(e.toString()); - } catch (SAXException e) { - s_logger.debug(e.toString()); - } catch (IOException e) { - s_logger.debug(e.toString()); + } catch (ParserConfigurationException | SAXException | IOException e) { + s_logger.error(String.format("Failed to parse snapshot configuration [%s] of VM [%s] due to: [%s].", snapshotXML, dm.getName(), e.getMessage()), e); } } catch (LibvirtException e) { - s_logger.debug("Fail to get the current vm snapshot for vm: " + dm.getName() + ", continue"); + s_logger.error(String.format("Failed to get the current snapshot of VM [%s] due to: [%s]. Continuing the migration process.", dm.getName(), e.getMessage()), e); } int flags = 2; // VIR_DOMAIN_SNAPSHOT_DELETE_METADATA_ONLY = 2 String[] snapshotNames = dm.snapshotListNames(); Arrays.sort(snapshotNames); + s_logger.debug(String.format("Found [%s] snapshots in VM [%s] to clean.", snapshotNames.length, dm.getName())); for (String snapshotName: snapshotNames) { DomainSnapshot snapshot = dm.snapshotLookupByName(snapshotName); Boolean isCurrent = (currentSnapshotName != null && currentSnapshotName.equals(snapshotName)) ? true: false; vmsnapshots.add(new Ternary(snapshotName, isCurrent, snapshot.getXMLDesc())); } for (String snapshotName: snapshotNames) { + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Cleaning snapshot [%s] of VM [%s] metadata.", snapshotNames, dm.getName())); + } DomainSnapshot snapshot = dm.snapshotLookupByName(snapshotName); snapshot.delete(flags); // clean metadata of vm snapshot } diff --git a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapper.java b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapper.java index 5c1c99aaabcb..812ca76ca46f 100644 --- a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapper.java +++ b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapper.java @@ -102,6 +102,9 @@ public Answer execute(final MigrateCommand command, final LibvirtComputingResour final Map vlanToPersistenceMap = command.getVlanToPersistenceMap(); final String destinationUri = createMigrationURI(command.getDestinationIp(), libvirtComputingResource); final List migrateDiskInfoList = command.getMigrateDiskInfoList(); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Trying to migrate VM [%s] to destination host: [%s].", vmName, destinationUri)); + } String result = null; @@ -121,7 +124,9 @@ public Answer execute(final MigrateCommand command, final LibvirtComputingResour conn = libvirtUtilitiesHelper.getConnectionByVmName(vmName); ifaces = libvirtComputingResource.getInterfaces(conn, vmName); disks = libvirtComputingResource.getDisks(conn, vmName); - + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Found domain with name [%s]. Starting VM migration to host [%s].", vmName, destinationUri)); + } VirtualMachineTO to = command.getVirtualMachine(); dm = conn.domainLookupByName(vmName); @@ -148,17 +153,23 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. final String target = command.getDestinationIp(); xmlDesc = dm.getXMLDesc(xmlFlag); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("VM [%s] with XML configuration [%s] will be migrated to host [%s].", vmName, xmlDesc, target)); + } // Limit the VNC password in case the length is greater than 8 characters // Since libvirt version 8 VNC passwords are limited to 8 characters String vncPassword = org.apache.commons.lang3.StringUtils.truncate(to.getVncPassword(), 8); - xmlDesc = replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, target, vncPassword); + xmlDesc = replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, target, vncPassword, vmName); String oldIsoVolumePath = getOldVolumePath(disks, vmName); String newIsoVolumePath = getNewVolumePathIfDatastoreHasChanged(libvirtComputingResource, conn, to); if (newIsoVolumePath != null && !newIsoVolumePath.equals(oldIsoVolumePath)) { s_logger.debug(String.format("Editing mount path of iso from %s to %s", oldIsoVolumePath, newIsoVolumePath)); xmlDesc = replaceDiskSourceFile(xmlDesc, newIsoVolumePath, vmName); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Replaced disk mount point [%s] with [%s] in VM [%s] XML configuration. New XML configuration is [%s].", oldIsoVolumePath, newIsoVolumePath, vmName, xmlDesc)); + } } // delete the metadata of vm snapshots before migration vmsnapshots = libvirtComputingResource.cleanVMSnapshotMetadata(dm); @@ -178,12 +189,24 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. final boolean migrateStorageManaged = command.isMigrateStorageManaged(); if (migrateStorage) { + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Changing VM [%s] volumes during migration to host: [%s].", vmName, target)); + } xmlDesc = replaceStorage(xmlDesc, mapMigrateStorage, migrateStorageManaged); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Changed VM [%s] XML configuration of used storage. New XML configuration is [%s].", vmName, xmlDesc)); + } } Map dpdkPortsMapping = command.getDpdkInterfaceMapping(); if (MapUtils.isNotEmpty(dpdkPortsMapping)) { + if (s_logger.isTraceEnabled()) { + s_logger.trace(String.format("Changing VM [%s] DPDK interfaces during migration to host: [%s].", vmName, target)); + } xmlDesc = replaceDpdkInterfaces(xmlDesc, dpdkPortsMapping); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Changed VM [%s] XML configuration of DPDK interfaces. New XML configuration is [%s].", vmName, xmlDesc)); + } } dconn = libvirtUtilitiesHelper.retrieveQemuConnection(destinationUri); @@ -193,7 +216,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. } //run migration in thread so we can monitor it - s_logger.info("Live migration of instance " + vmName + " initiated to destination host: " + dconn.getURI()); + s_logger.info(String.format("Starting live migration of instance [%s] to destination host [%s] having the final XML configuration: [%s].", vmName, dconn.getURI(), xmlDesc)); final ExecutorService executor = Executors.newFixedThreadPool(1); boolean migrateNonSharedInc = command.isMigrateNonSharedInc() && !migrateStorageManaged; @@ -235,13 +258,13 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. if (state != null && state == DomainState.VIR_DOMAIN_RUNNING) { try { DomainJobInfo job = dm.getJobInfo(); - s_logger.info("Aborting " + vmName + " domain job: " + job); + s_logger.info(String.format("Aborting migration of VM [%s] with domain job [%s] due to time out after %d seconds.", vmName, job, migrateWait)); dm.abortJob(); - result = String.format("Migration of VM %s was cancelled by cloudstack due to time out after %d seconds", vmName, migrateWait); + result = String.format("Migration of VM [%s] was cancelled by CloudStack due to time out after %d seconds.", vmName, migrateWait); s_logger.debug(result); break; } catch (final LibvirtException e) { - s_logger.info("Failed to abort the vm migration job of vm " + vmName + " : " + e.getMessage()); + s_logger.error(String.format("Failed to abort the VM migration job of VM [%s] due to: [%s].", vmName, e.getMessage()), e); } } } @@ -266,16 +289,19 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. } } } - s_logger.info("Migration thread for " + vmName + " is done"); + s_logger.info(String.format("Migration thread of VM [%s] finished.", vmName)); destDomain = migrateThread.get(AgentPropertiesFileHandler.getPropertyValue(AgentProperties.VM_MIGRATE_DOMAIN_RETRIEVE_TIMEOUT), TimeUnit.SECONDS); if (destDomain != null) { + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Cleaning the disks of VM [%s] in the source pool after VM migration finished.", vmName)); + } deleteOrDisconnectDisksOnSourcePool(libvirtComputingResource, migrateDiskInfoList, disks); } } catch (final LibvirtException e) { - s_logger.debug("Can't migrate domain: " + e.getMessage()); + s_logger.error(String.format("Can't migrate domain [%s] due to: [%s].", vmName, e.getMessage()), e); result = e.getMessage(); if (result.startsWith("unable to connect to server") && result.endsWith("refused")) { result = String.format("Migration was refused connection to destination: %s. Please check libvirt configuration compatibility and firewall rules on the source and destination hosts.", destinationUri); @@ -288,7 +314,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. | SAXException | TransformerException | URISyntaxException e) { - s_logger.debug(String.format("%s : %s", e.getClass().getSimpleName(), e.getMessage())); + s_logger.error(String.format("Can't migrate domain [%s] due to: [%s].", vmName, e.getMessage()), e); if (result == null) { result = "Exception during migrate: " + e.getMessage(); } @@ -317,8 +343,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0. } } - if (result != null) { - } else { + if (result == null) { libvirtComputingResource.destroyNetworkRulesForVM(conn, vmName); for (final InterfaceDef iface : ifaces) { String vlanId = libvirtComputingResource.getVlanIdFromBridgeName(iface.getBrName()); @@ -456,11 +481,12 @@ protected MigrateDiskInfo searchDiskDefOnMigrateDiskInfoList(List= 0) { final int end = xmlDesc.lastIndexOf(GRAPHICS_ELEM_END) + GRAPHICS_ELEM_END.length(); if (end > begin) { + String originalGraphElem = xmlDesc.substring(begin, end); String graphElem = xmlDesc.substring(begin, end); graphElem = graphElem.replaceAll("listen='[a-zA-Z0-9\\.]*'", "listen='" + target + "'"); graphElem = graphElem.replaceAll("address='[a-zA-Z0-9\\.]*'", "address='" + target + "'"); @@ -468,6 +494,9 @@ String replaceIpForVNCInDescFileAndNormalizePassword(String xmlDesc, final Strin graphElem = graphElem.replaceAll("passwd='([^\\s]+)'", "passwd='" + vncPassword + "'"); } xmlDesc = xmlDesc.replaceAll(GRAPHICS_ELEM_START + CONTENTS_WILDCARD + GRAPHICS_ELEM_END, graphElem); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Replaced the VNC IP address [%s] with [%s] in VM [%s].", originalGraphElem, graphElem, vmName)); + } } } return xmlDesc; diff --git a/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapperTest.java b/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapperTest.java index 23f0ff911283..ae2e4cc41c25 100644 --- a/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapperTest.java +++ b/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapperTest.java @@ -571,7 +571,7 @@ public void setup() throws Exception { @Test public void testReplaceIpForVNCInDescFile() { final String targetIp = "192.168.22.21"; - final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(fullfile, targetIp, null); + final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(fullfile, targetIp, null, ""); assertTrue("transformation does not live up to expectation:\n" + result, targetfile.equals(result)); } @@ -595,7 +595,7 @@ public void testReplaceIpAndPasswordForVNCInDesc() { ""; final String targetIp = "10.10.10.10"; final String password = "12345678"; - final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, targetIp, password); + final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, targetIp, password, ""); assertTrue("transformation does not live up to expectation:\n" + result, expectedXmlDesc.equals(result)); } @@ -619,7 +619,7 @@ public void testReplaceFqdnAndPasswordForVNCInDesc() { ""; final String targetIp = "localhost.localdomain"; final String password = "12345678"; - final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, targetIp, password); + final String result = libvirtMigrateCmdWrapper.replaceIpForVNCInDescFileAndNormalizePassword(xmlDesc, targetIp, password, ""); assertTrue("transformation does not live up to expectation:\n" + result, expectedXmlDesc.equals(result)); }