Skip to content

KVM VM migration log refactor #14224

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
erikbocks wants to merge 7 commits into
base: main
Choose a base branch
from
Open

KVM VM migration log refactor #14224

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
539d845
KVM VM migration logs refactoring
erikbocks Sep 22, 2026
d49e548
Fix merge conflict
erikbocks Sep 22, 2026
30ca4ce
Address copilot and Daman reviews
erikbocks Oct 13, 2026
4322354
Address copilot review
erikbocks Oct 13, 2026
96eb57a
Improve logging for VM operations and exceptions
erikbocks Oct 14, 2026
7d743e2
Address copilot review
erikbocks Oct 19, 2026
5bad458
Address copilot's standardization suggestions
erikbocks Nov 12, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 2 additions & 3 deletions engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3793,10 +3793,9 @@ private void orchestrateMigrateWithStorage(final String vmUuid, final long srcHo
AttachOrDettachConfigDriveCommand dettachCommand = new AttachOrDettachConfigDriveCommand(vm.getInstanceName(), vmData, VmConfigDriveLabel.value(), false);
try {
_agentMgr.send(srcHost.getId(), dettachCommand);
logger.debug("Deleted config drive ISO for vm {} in host {}", vm.getInstanceName(), srcHost);
logger.debug("Deleted config drive ISO for VM {} in host with ID {}.", vm.getInstanceName(), srcHost.getId());
} catch (OperationTimedoutException e) {
logger.error("TIme out occurred while exeuting command AttachOrDettachConfigDrive {}", e.getMessage(), e);

logger.error("Timeout occurred while executing command AttachOrDettachConfigDrive for VM {} on source host {}", vm.getInstanceName(), srcHost.getId(), e);
}
}
}
Expand Down
67 changes: 30 additions & 37 deletions ...src/main/java/com/cloud/hypervisor/kvm/resource/wrapper/LibvirtMigrateCommandWrapper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,9 +108,7 @@ public Answer execute(final MigrateCommand command, final LibvirtComputingResour
final Map<String, Boolean> vlanToPersistenceMap = command.getVlanToPersistenceMap();
final String destinationUri = createMigrationURI(command.getDestinationIp(), libvirtComputingResource);
final List<MigrateDiskInfo> migrateDiskInfoList = command.getMigrateDiskInfoList();
if (logger.isDebugEnabled()) {
logger.debug(String.format("Trying to migrate VM [%s] to destination host: [%s].", vmName, destinationUri));
}
logger.debug("Trying to migrate VM [{}] to destination host: {}.", vmName, destinationUri);

String result = null;
Command.State commandState = null;
Expand All @@ -133,9 +131,7 @@ public Answer execute(final MigrateCommand command, final LibvirtComputingResour
conn = libvirtUtilitiesHelper.getConnectionByVmName(vmName);
ifaces = libvirtComputingResource.getInterfaces(conn, vmName);
disks = libvirtComputingResource.getDisks(conn, vmName);
if (logger.isDebugEnabled()) {
logger.debug(String.format("Found domain with name [%s]. Starting VM migration to host [%s].", vmName, destinationUri));
}
logger.debug("Found domain with name {}. Starting VM migration to host {}.", vmName, destinationUri);
to = command.getVirtualMachine();

dm = conn.domainLookupByName(vmName);
Expand Down Expand Up @@ -163,7 +159,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
final String target = command.getDestinationIp();
xmlDesc = dm.getXMLDesc(xmlFlag);
if (logger.isDebugEnabled()) {
logger.debug("VM {} with XML configuration {} will be migrated to host {}.", vmName, maskSensitiveInfoInXML(xmlDesc), target);
logger.debug("VM [{}] will be migrated to host {} with the following XML configuration retrieved with flag [{}]: {}.", vmName, target, xmlFlag, maskSensitiveInfoInXML(xmlDesc));
}

// Limit the VNC password in case the length is greater than 8 characters
Expand All @@ -175,7 +171,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
String oldIsoVolumePath = getOldVolumePath(disks, vmName);
String newIsoVolumePath = getNewVolumePathIfDatastoreHasChanged(libvirtComputingResource, conn, to);
if (newIsoVolumePath != null && !newIsoVolumePath.equals(oldIsoVolumePath)) {
logger.debug(String.format("Editing mount path of ISO from %s to %s", oldIsoVolumePath, newIsoVolumePath));
logger.debug("Editing mount path of ISO from {} to {}.", oldIsoVolumePath, newIsoVolumePath);
xmlDesc = replaceDiskSourceFile(xmlDesc, newIsoVolumePath, vmName);
if (logger.isDebugEnabled()) {
logger.debug("Replaced disk mount point {} with {} in Instance {} XML configuration. New XML configuration is {}.", oldIsoVolumePath, newIsoVolumePath, vmName, maskSensitiveInfoInXML(xmlDesc));
Expand Down Expand Up @@ -208,24 +204,20 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
Set<String> migrateDiskLabels = null;

if (migrateStorage) {
if (logger.isDebugEnabled()) {
logger.debug("Changing VM {} volumes during migration to host: {}.", vmName, target);
}
logger.debug("Changing VM [{}] volumes during migration to host: {}.", vmName, target);
xmlDesc = replaceStorage(xmlDesc, mapMigrateStorage, migrateStorageManaged);
if (logger.isDebugEnabled()) {
logger.debug("Changed VM {} XML configuration of used storage. New XML configuration is {}.", vmName, maskSensitiveInfoInXML(xmlDesc));
logger.debug("Changed VM [{}] XML configuration of used storage. New XML configuration is {}.", vmName, maskSensitiveInfoInXML(xmlDesc));
}
migrateDiskLabels = getMigrateStorageDeviceLabels(disks, mapMigrateStorage);
}

Map<String, DpdkTO> dpdkPortsMapping = command.getDpdkInterfaceMapping();
if (MapUtils.isNotEmpty(dpdkPortsMapping)) {
if (logger.isTraceEnabled()) {
logger.trace("Changing VM {} DPDK interfaces during migration to host: {}.", vmName, target);
}
logger.trace("Changing VM [{}] DPDK interfaces during migration to host: {}.", vmName, target);
xmlDesc = replaceDpdkInterfaces(xmlDesc, dpdkPortsMapping);
if (logger.isDebugEnabled()) {
logger.debug("Changed VM {} XML configuration of DPDK interfaces. New XML configuration is {}.", vmName, maskSensitiveInfoInXML(xmlDesc));
logger.debug("Changed VM [{}] XML configuration of DPDK interfaces. New XML configuration is {}.", vmName, maskSensitiveInfoInXML(xmlDesc));
}
}

Expand Down Expand Up @@ -273,38 +265,37 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
final int setDowntime = dm.migrateSetMaxDowntime(migrateDowntime);
if (setDowntime == 0 ) {
isMigrateDowntimeSet = true;
logger.debug("Set max downtime for migration of " + vmName + " to " + String.valueOf(migrateDowntime) + "ms");
logger.debug("Set max downtime for migration of {} to {}ms.", vmName, migrateDowntime);
}
} catch (final LibvirtException e) {
logger.debug("Failed to set max downtime for migration, perhaps migration completed? Error: " + e.getMessage());
logger.debug("Failed to set max downtime for migration. It might happen if the migration has already completed.", e);
}
}
if (sleeptime % 1000 == 0) {
logger.info("Waiting for migration of " + vmName + " to complete, waited " + sleeptime + "ms");
logger.info("Waiting for migration of {} to complete, waited {}ms.", vmName, sleeptime);
}

// abort the vm migration if the job is executed more than vm.migrate.wait
if (migrateWait > 0 && sleeptime > migrateWait * 1000) {
DomainState state = null;
try {
state = dm.getInfo().state;
logger.info("VM domain state when trying to abort migration : {}", state);
logger.info("VM domain state when trying to abort migration: {}.", state);
} catch (final LibvirtException e) {
logger.info("Couldn't get VM domain state after " + sleeptime + "ms: " + e.getMessage());
logger.warn("Could not get VM domain state after {}ms.", sleeptime, e);
}
if (state != null && (state == DomainState.VIR_DOMAIN_RUNNING || state == DomainState.VIR_DOMAIN_PAUSED)) {
try {
DomainJobInfo job = dm.getJobInfo();
logger.warn("Aborting migration of VM {} with domain job [{}] due to timeout after {} seconds. " +
"Job stats: data processed={} bytes, data remaining={} bytes", vmName, job, migrateWait, job.getDataProcessed(), job.getDataRemaining());
logger.warn("Aborting migration of VM [{}] with domain job [{}] due to timeout after {} seconds. Job stats: data processed={} bytes, data remaining={} bytes.", vmName, job, migrateWait, job.getDataProcessed(), job.getDataRemaining());
dm.abortJob();
result = String.format("Migration of VM [%s] was cancelled by CloudStack due to time out after %d seconds.", vmName, migrateWait);
commandState = Command.State.FAILED;
libvirtComputingResource.createOrUpdateLogFileForCommand(command, commandState);
logger.debug(result);
break;
} catch (final LibvirtException e) {
logger.error(String.format("Failed to abort the VM migration job of VM [%s] due to: [%s].", vmName, e.getMessage()), e);
logger.error("Failed to abort the VM migration job of VM [{}].", vmName, e);
}
}
}
Expand All @@ -314,29 +305,27 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
DomainState state = null;
try {
state = dm.getInfo().state;
logger.info("VM domain state when trying to pause VM for migration: {}", state);
logger.info("VM domain state when trying to pause VM for migration: {}.", state);
} catch (final LibvirtException e) {
logger.info("Couldn't get VM domain state after " + sleeptime + "ms: " + e.getMessage());
logger.warn("Could not get VM domain state after {}ms.", sleeptime, e);
}
if (state != null && state == DomainState.VIR_DOMAIN_RUNNING) {
try {
logger.info("Pausing VM " + vmName + " due to property vm.migrate.pauseafter setting to " + migratePauseAfter + "ms to complete migration");
logger.info("Pausing VM [{}] due to property vm.migrate.pauseafter setting to {}ms to complete migration.", vmName, migratePauseAfter);
dm.suspend();
} catch (final LibvirtException e) {
// pause could be racy if it attempts to pause right when vm is finished, simply warn
logger.info("Failed to pause vm " + vmName + " : " + e.getMessage());
logger.warn("Failed to pause VM [{}]", vmName, e);
}
}
}
}
logger.info(String.format("Migration thread of VM [%s] finished.", vmName));
logger.info("Migration thread of VM [{}] finished.", vmName);
Comment thread
erikbocks marked this conversation as resolved.
Resolved

destDomain = migrateThread.get(AgentPropertiesFileHandler.getPropertyValue(AgentProperties.VM_MIGRATE_DOMAIN_RETRIEVE_TIMEOUT), TimeUnit.SECONDS);

if (destDomain != null) {
if (logger.isDebugEnabled()) {
logger.debug(String.format("Cleaning the disks of VM [%s] in the source pool after VM migration finished.", vmName));
}
logger.debug("Cleaning the disks of VM [{}] in the source pool after VM migration finished.", vmName);
resumeDomainIfPaused(destDomain, vmName);

// For cross-pool CLVM migration, skip deactivation so the source LV stays
Expand All @@ -351,7 +340,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
}

} catch (final LibvirtException e) {
logger.error(String.format("Can't migrate domain [%s] due to: [%s].", vmName, e.getMessage()), e);
logMigrationFailure(vmName, destinationUri, e);
result = e.getMessage();
if (result.startsWith("unable to connect to server") && result.endsWith("refused")) {
logger.debug("Migration failed as connection to destination [{}] was refused. Please check libvirt configuration compatibility and firewall rules on the source and destination hosts.", destinationUri);
Expand All @@ -365,7 +354,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
| SAXException
| TransformerException
| URISyntaxException e) {
logger.error(String.format("Can't migrate domain [%s] due to: [%s].", vmName, e.getMessage()), e);
logMigrationFailure(vmName, destinationUri, e);
if (result == null) {
result = "Exception during migrate: " + e.getMessage();
}
Expand Down Expand Up @@ -402,7 +391,7 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
}

if (result == null) {
logger.info("Post-migration cleanup for VM {}: ", vmName);
logger.info("Post-migration cleanup for VM [{}].", vmName);
libvirtComputingResource.destroyNetworkRulesForVM(conn, vmName);
for (final InterfaceDef iface : ifaces) {
String vlanId = libvirtComputingResource.getVlanIdFromBridgeName(iface.getBrName());
Expand All @@ -416,14 +405,18 @@ Use VIR_DOMAIN_XML_SECURE (value = 1) prior to v1.0.0.
commandState = Command.State.COMPLETED;
libvirtComputingResource.createOrUpdateLogFileForCommand(command, commandState);
} else if (commandState == null) {
logger.error("Migration of VM {} failed with result: {}", vmName, result);
logger.error("Migration of VM [{}] failed with result: {}.", vmName, result);
commandState = Command.State.FAILED;
libvirtComputingResource.createOrUpdateLogFileForCommand(command, commandState);
}

return new MigrateAnswer(command, result == null, result, null);
}

private void logMigrationFailure(String vmName, String destinationUri, Exception exception) {
logger.error("Could not migrate domain [{}] to host [{}].", vmName, destinationUri, exception);
}

private DomainState getDestDomainState(Domain destDomain, String vmName) {
DomainState dmState = null;
try {
Expand Down Expand Up @@ -753,7 +746,7 @@ 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);
logger.debug("Replaced the VNC IP address {} with {} in VM {}.", maskSensitiveInfoInXML(originalGraphElem), maskSensitiveInfoInXML(graphElem), vmName);
logger.debug("Replaced the VNC IP address {} with {} in VM [{}].", maskSensitiveInfoInXML(originalGraphElem), maskSensitiveInfoInXML(graphElem), vmName);
}
}
return xmlDesc;
Expand Down
Loading