From 2b120bdf4071d6fbf33536689b637518c5a3a12f Mon Sep 17 00:00:00 2001 From: Siddharthan P S Date: Fri, 13 Nov 2026 07:44:10 -0500 Subject: [PATCH 1/2] Fix interrupted KVM snapshot leaving VM on orphan overlay (#14691) Script.runSimpleBashScriptWithFullResult now includes error output in exceptions, enabling retry logic for transient virsh errors. Snapshot markers store VM name, disk label, overlay path for recovery. reconcileSnapshotMarkers() fully implemented with blockcommit for running VMs and qemu-img commit for offline cases. Agent reconnects instead of System.exit(1) on ReadyCommand failure. Removed duplicate SNAPSHOT_MARKER_DIR constant. --- .../src/main/java/com/cloud/agent/Agent.java | 33 +- .../kvm/storage/KVMStorageProcessor.java | 395 +++++++++++++++--- .../java/com/cloud/utils/script/Script.java | 7 +- 3 files changed, 375 insertions(+), 60 deletions(-) diff --git a/agent/src/main/java/com/cloud/agent/Agent.java b/agent/src/main/java/com/cloud/agent/Agent.java index 275fd41edc34..3cdca5cfb949 100644 --- a/agent/src/main/java/com/cloud/agent/Agent.java +++ b/agent/src/main/java/com/cloud/agent/Agent.java @@ -663,6 +663,35 @@ protected void reconnect(final Link link, String preferredMSHost, boolean forTra logger.info("Connected to the host: {}", shell.getConnectedHost()); } + protected void waitForCommandsAndReconnect(final Link link) { + int inProgress = commandsInProgress.get(); + if (inProgress > 0) { + logger.warn("Agent disconnected with {} command(s) still in progress. Waiting for them to complete before reconnecting.", inProgress); + + long maxWaitMs = 300000; + long waitedMs = 0; + while (commandsInProgress.get() > 0 && waitedMs < maxWaitMs) { + try { + Thread.sleep(1000); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + break; + } + waitedMs += 1000; + } + + if (commandsInProgress.get() > 0) { + logger.warn("Timed out waiting for {} command(s) to complete after {} ms. Proceeding with reconnect — " + + "in-progress commands (e.g. snapshot merges) may not have completed.", commandsInProgress.get(), waitedMs); + } else { + logger.info("All in-progress commands completed. Proceeding with reconnect."); + } + } + + logger.info("Reconnecting instead of exiting to avoid losing in-flight work (e.g. snapshot overlays)."); + reconnect(link); + } + protected void closeAndTerminateLink(final Link link) { if (link == null) { return; @@ -700,7 +729,7 @@ public void processStartupAnswer(final Answer answer, final Response response, f reconnect(link); return; } - System.exit(1); + waitForCommandsAndReconnect(link); } if (!answerValid) { logger.warn("Threw away a startup answer because we're reconnecting."); @@ -772,7 +801,7 @@ protected void processRequest(final Request request, final Link link) { reconnect(link); return; } - System.exit(1); + waitForCommandsAndReconnect(link); return; } else if (cmd instanceof MaintainCommand) { logger.debug("Received maintainCommand, do not cancel current tasks"); diff --git a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessor.java b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessor.java index 235949502c71..543ed454dc48 100644 --- a/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessor.java +++ b/plugins/hypervisors/kvm/src/main/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessor.java @@ -18,12 +18,9 @@ */ package com.cloud.hypervisor.kvm.storage; -import com.cloud.offering.DiskOffering; import static com.cloud.utils.NumbersUtil.toHumanReadableSize; import static com.cloud.utils.storage.S3.S3Utils.putFile; -import com.cloud.template.TemplateManager; - import java.io.File; import java.io.FileNotFoundException; import java.io.FileOutputStream; @@ -44,6 +41,10 @@ import java.util.Map; import java.util.Set; import java.util.UUID; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.locks.ReentrantLock; import java.util.stream.Collectors; import javax.naming.ConfigurationException; @@ -56,12 +57,63 @@ import javax.xml.xpath.XPathExpressionException; import javax.xml.xpath.XPathFactory; +import com.ceph.rados.IoCTX; +import com.ceph.rados.Rados; +import com.ceph.rados.exceptions.ErrorCode; +import com.ceph.rados.exceptions.RadosException; +import com.ceph.rbd.Rbd; +import com.ceph.rbd.RbdException; +import com.ceph.rbd.RbdImage; +import com.ceph.rbd.jna.RbdSnapInfo; +import com.cloud.agent.api.Answer; import com.cloud.agent.api.Command; +import com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer; +import com.cloud.agent.api.to.DataObjectType; +import com.cloud.agent.api.to.DataStoreTO; +import com.cloud.agent.api.to.DataTO; +import com.cloud.agent.api.to.DiskTO; +import com.cloud.agent.api.to.NfsTO; +import com.cloud.agent.api.to.S3TO; +import com.cloud.agent.properties.AgentProperties; +import com.cloud.agent.properties.AgentPropertiesFileHandler; +import com.cloud.exception.InternalErrorException; +import com.cloud.exception.InvalidParameterValueException; +import com.cloud.hypervisor.Hypervisor; +import com.cloud.hypervisor.kvm.resource.LibvirtComputingResource; +import com.cloud.hypervisor.kvm.resource.LibvirtConnection; +import com.cloud.hypervisor.kvm.resource.LibvirtDomainXMLParser; +import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef; +import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DeviceType; +import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DiscardType; +import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DiskProtocol; import com.cloud.hypervisor.kvm.resource.LibvirtXMLParser; +import com.cloud.offering.DiskOffering; +import com.cloud.storage.JavaStorageLayer; +import com.cloud.storage.MigrationOptions; +import com.cloud.storage.ScopeType; +import com.cloud.storage.Storage; +import com.cloud.storage.Storage.ImageFormat; +import com.cloud.storage.Storage.StoragePoolType; +import com.cloud.storage.StorageLayer; +import com.cloud.storage.Volume; import com.cloud.storage.clvm.ClvmPoolManager; +import com.cloud.storage.resource.StorageProcessor; +import com.cloud.storage.template.Processor; +import com.cloud.storage.template.Processor.FormatInfo; +import com.cloud.storage.template.QCOW2Processor; +import com.cloud.storage.template.TemplateConstants; +import com.cloud.storage.template.TemplateLocation; +import com.cloud.template.TemplateManager; +import com.cloud.utils.Pair; +import com.cloud.utils.UriUtils; +import com.cloud.utils.exception.CloudRuntimeException; +import com.cloud.utils.script.Script; +import com.cloud.utils.storage.S3.S3Utils; +import com.cloud.vm.VmDetailConstants; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.JsonNode; import com.fasterxml.jackson.databind.ObjectMapper; + import org.apache.cloudstack.agent.directdownload.DirectDownloadAnswer; import org.apache.cloudstack.agent.directdownload.DirectDownloadCommand; import org.apache.cloudstack.direct.download.DirectDownloadHelper; @@ -114,55 +166,6 @@ import org.libvirt.DomainInfo; import org.libvirt.DomainSnapshot; import org.libvirt.LibvirtException; - -import com.ceph.rados.IoCTX; -import com.ceph.rados.Rados; -import com.ceph.rados.exceptions.ErrorCode; -import com.ceph.rados.exceptions.RadosException; -import com.ceph.rbd.Rbd; -import com.ceph.rbd.RbdException; -import com.ceph.rbd.RbdImage; -import com.ceph.rbd.jna.RbdSnapInfo; -import com.cloud.agent.api.Answer; -import com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer; -import com.cloud.agent.api.to.DataObjectType; -import com.cloud.agent.api.to.DataStoreTO; -import com.cloud.agent.api.to.DataTO; -import com.cloud.agent.api.to.DiskTO; -import com.cloud.agent.api.to.NfsTO; -import com.cloud.agent.api.to.S3TO; -import com.cloud.agent.properties.AgentProperties; -import com.cloud.agent.properties.AgentPropertiesFileHandler; -import com.cloud.exception.InternalErrorException; -import com.cloud.exception.InvalidParameterValueException; -import com.cloud.hypervisor.Hypervisor; -import com.cloud.hypervisor.kvm.resource.LibvirtComputingResource; -import com.cloud.hypervisor.kvm.resource.LibvirtConnection; -import com.cloud.hypervisor.kvm.resource.LibvirtDomainXMLParser; -import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef; -import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DeviceType; -import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DiscardType; -import com.cloud.hypervisor.kvm.resource.LibvirtVMDef.DiskDef.DiskProtocol; -import com.cloud.storage.JavaStorageLayer; -import com.cloud.storage.MigrationOptions; -import com.cloud.storage.ScopeType; -import com.cloud.storage.Storage; -import com.cloud.storage.Storage.ImageFormat; -import com.cloud.storage.Storage.StoragePoolType; -import com.cloud.storage.StorageLayer; -import com.cloud.storage.Volume; -import com.cloud.storage.resource.StorageProcessor; -import com.cloud.storage.template.Processor; -import com.cloud.storage.template.Processor.FormatInfo; -import com.cloud.storage.template.QCOW2Processor; -import com.cloud.storage.template.TemplateConstants; -import com.cloud.storage.template.TemplateLocation; -import com.cloud.utils.Pair; -import com.cloud.utils.UriUtils; -import com.cloud.utils.exception.CloudRuntimeException; -import com.cloud.utils.script.Script; -import com.cloud.utils.storage.S3.S3Utils; -import com.cloud.vm.VmDetailConstants; import org.w3c.dom.Document; import org.w3c.dom.Node; import org.w3c.dom.NodeList; @@ -216,6 +219,18 @@ public class KVMStorageProcessor implements StorageProcessor { private static final String DOMJOBABORT_COMMAND = "virsh domjobabort --domain %s"; + private static final String SNAPSHOT_MARKER_PREFIX = ".snapshot_marker_"; + private static final String SNAPSHOT_MARKER_DIR = "/var/cache/cloudstack/snapshot_markers"; + + /** + * Per-VM lock to serialize NAS backups (virsh backup-begin) with volume snapshots (virsh blockcommit). + * Both operations use libvirt block jobs on the same domain and can conflict with "disk already in active block job". + */ + private final ConcurrentMap vmBlockJobLocks = new ConcurrentHashMap<>(); + + private ReentrantLock getVmBlockJobLock(String vmName) { + return vmBlockJobLocks.computeIfAbsent(vmName, k -> new ReentrantLock()); + } private static final String DUMMY_VM_XML = "\n" + " %s\n" + " 256\n" + @@ -2243,9 +2258,25 @@ private SnapshotObjectTO takeIncrementalVolumeSnapshotOfRunningVm(SnapshotObject createFolderOnCorrectStorage(primaryPool, secondaryPool, fullSnapshotPathAndDirPath); - if (Script.runSimpleBashScript(backupCommand) == null) { - throw new CloudRuntimeException(String.format("Error backing up using backupXML [%s], checkpointXML [%s] for volume [%s].", backupXml, checkpointXml, - volumeObjectTo)); + ReentrantLock vmLock = getVmBlockJobLock(vmName); + boolean lockAcquired = false; + try { + lockAcquired = vmLock.tryLock(incrementalSnapshotTimeout, TimeUnit.MILLISECONDS); + if (!lockAcquired) { + throw new CloudRuntimeException(String.format("Could not acquire block job lock for VM [%s] within timeout [%d ms]. Another block job (snapshot/backup) may be in progress.", vmName, incrementalSnapshotTimeout)); + } + + if (Script.runSimpleBashScript(backupCommand) == null) { + throw new CloudRuntimeException(String.format("Error backing up using backupXML [%s], checkpointXML [%s] for volume [%s].", backupXml, checkpointXml, + volumeObjectTo)); + } + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new CloudRuntimeException("Interrupted while waiting for block job lock for VM [" + vmName + "]", e); + } finally { + if (lockAcquired) { + vmLock.unlock(); + } } try { @@ -2516,10 +2547,16 @@ private SnapshotObjectTO takeFullVolumeSnapshotOfRunningVm(CreateObjectCommand c ObjectUtils.defaultIfNull(secondaryPool, primaryPool)); validateAvailableSizeOnPoolToTakeVolumeSnapshot(primaryPool, disk); + + writeSnapshotMarker(primaryPool, diskPath, snapshotName); + String relativePath = null; try { String diskLabel = takeVolumeSnapshot(resource.getDisks(conn, vmName), snapshotName, diskPath, vm); + String overlayPath = resource.getSnapshotTemporaryPath(diskPath, snapshotName); + updateSnapshotMarker(primaryPool, diskPath, snapshotName, vmName, diskLabel, overlayPath); + Pair fullSnapPathAndDirPath = getFullSnapshotOrCheckpointPathAndDirPathOnCorrectStorage(primaryPool, secondaryPool, snapshotName, volume, false); snapshotPath = fullSnapPathAndDirPath.first(); @@ -2528,10 +2565,29 @@ private SnapshotObjectTO takeFullVolumeSnapshotOfRunningVm(CreateObjectCommand c String convertResult = convertBaseFileToSnapshotFileInStorageDir(ObjectUtils.defaultIfNull(secondaryPool, primaryPool), disk, snapshotPath, directoryPath, volume, cmd.getWait()); - resource.mergeDeltaIntoBaseFile(vm, diskLabel, diskPath, null, true, snapshotName, volume, conn); + ReentrantLock vmLock = getVmBlockJobLock(vmName); + boolean lockAcquired = false; + try { + lockAcquired = vmLock.tryLock(incrementalSnapshotTimeout, TimeUnit.MILLISECONDS); + if (!lockAcquired) { + throw new CloudRuntimeException(String.format("Could not acquire block job lock for VM [%s] within timeout [%d ms]. Another block job (snapshot/backup) may be in progress.", vmName, incrementalSnapshotTimeout)); + } + + resource.mergeDeltaIntoBaseFile(vm, diskLabel, diskPath, null, true, snapshotName, volume, conn); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new CloudRuntimeException("Interrupted while waiting for block job lock for VM [" + vmName + "]", e); + } finally { + if (lockAcquired) { + vmLock.unlock(); + } + } + + removeSnapshotMarker(primaryPool, diskPath, snapshotName); validateConvertResult(convertResult, snapshotPath); } catch (LibvirtException e) { + removeSnapshotMarker(primaryPool, diskPath, snapshotName); if (!e.getMessage().contains(LIBVIRT_OPERATION_NOT_SUPPORTED_MESSAGE)) { throw e; } @@ -3609,4 +3665,231 @@ public KVMStoragePool getTemplateSourcePoolUsingMigrationOptions(KVMStoragePool return storagePoolMgr.getStoragePool(migrationOptions.getSrcPoolType(), migrationOptions.getSrcPoolUuid()); } + + /** + * Write a marker file before creating a snapshot overlay. + * Marker format: poolUuid|volumePath|snapshotName|vmName|diskLabel|overlayPath|timestamp + */ + protected void writeSnapshotMarker(KVMStoragePool pool, String volumePath, String snapshotName) { + writeSnapshotMarker(pool, volumePath, snapshotName, null, null, null); + } + + protected void writeSnapshotMarker(KVMStoragePool pool, String volumePath, String snapshotName, + String vmName, String diskLabel, String overlayPath) { + try { + File markerDir = new File(SNAPSHOT_MARKER_DIR); + if (!markerDir.exists()) { + markerDir.mkdirs(); + } + String markerName = SNAPSHOT_MARKER_PREFIX + pool.getUuid() + "_" + volumePath.replace("/", "_") + "_" + snapshotName; + File markerFile = new File(markerDir, markerName); + String content = String.join("|", + pool.getUuid(), + volumePath, + snapshotName, + StringUtils.defaultString(vmName), + StringUtils.defaultString(diskLabel), + StringUtils.defaultString(overlayPath), + String.valueOf(System.currentTimeMillis())); + try (FileOutputStream fos = new FileOutputStream(markerFile)) { + fos.write(content.getBytes()); + } + logger.debug("Wrote snapshot marker: {}", markerFile.getAbsolutePath()); + } catch (IOException e) { + logger.warn("Failed to write snapshot marker for volume {} snapshot {}: {}", volumePath, snapshotName, e.getMessage()); + } + } + + protected void updateSnapshotMarker(KVMStoragePool pool, String volumePath, String snapshotName, + String vmName, String diskLabel, String overlayPath) { + writeSnapshotMarker(pool, volumePath, snapshotName, vmName, diskLabel, overlayPath); + } + + /** + * Remove the snapshot marker after successful merge. + */ + protected void removeSnapshotMarker(KVMStoragePool pool, String volumePath, String snapshotName) { + try { + String markerName = SNAPSHOT_MARKER_PREFIX + pool.getUuid() + "_" + volumePath.replace("/", "_") + "_" + snapshotName; + File markerFile = new File(SNAPSHOT_MARKER_DIR, markerName); + if (markerFile.exists()) { + markerFile.delete(); + logger.debug("Removed snapshot marker: {}", markerFile.getAbsolutePath()); + } + } catch (Exception e) { + logger.warn("Failed to remove snapshot marker for volume {} snapshot {}: {}", volumePath, snapshotName, e.getMessage()); + } + } + + /** + * Reconcile incomplete snapshots by checking for marker files on agent startup. + * If a marker exists, the agent died during a snapshot and the merge may not have completed. + * + * Strategy per marker: + * - Overlay gone: snapshot completed or was cleaned up, remove marker + * - VM still running on overlay: blockcommit --active --pivot back to base + * - VM already on base: overlay is orphaned, remove marker + * - Domain gone, overlay exists: offline qemu-img commit + * - Base modified since marker: cannot safely commit, alert and keep marker + */ + protected void reconcileSnapshotMarkers() { + File markerDir = new File(SNAPSHOT_MARKER_DIR); + if (!markerDir.exists() || !markerDir.isDirectory()) { + return; + } + + File[] markers = markerDir.listFiles((dir, name) -> name.startsWith(SNAPSHOT_MARKER_PREFIX)); + if (markers == null || markers.length == 0) { + return; + } + + logger.info("Found {} snapshot marker(s) to reconcile", markers.length); + for (File marker : markers) { + reconcileSingleMarker(marker); + } + } + + protected void reconcileSingleMarker(File marker) { + try { + String content = new String(Files.readAllBytes(marker.toPath())).trim(); + String[] parts = content.split("\\|", -1); + if (parts.length < 3) { + logger.error("Invalid snapshot marker format in {}: {}", marker.getName(), content); + return; + } + + String poolUuid = parts[0]; + String volumePath = parts[1]; + String snapshotName = parts[2]; + String vmName = parts.length > 3 ? parts[3] : ""; + String diskLabel = parts.length > 4 ? parts[4] : ""; + String overlayPath = parts.length > 5 ? parts[5] : ""; + + if (StringUtils.isEmpty(overlayPath)) { + overlayPath = resource.getSnapshotTemporaryPath(volumePath, snapshotName); + } + + logger.warn("Reconciling incomplete snapshot: pool={}, volume={}, snapshot={}, vm={}, disk={}, overlay={}", + poolUuid, volumePath, snapshotName, vmName, diskLabel, overlayPath); + + File overlayFile = new File(overlayPath); + if (!overlayFile.exists()) { + logger.info("Overlay file {} no longer exists. Snapshot may have completed or been cleaned up. Removing marker.", overlayPath); + marker.delete(); + return; + } + + if (StringUtils.isNotEmpty(vmName)) { + if (reconcileWithRunningDomain(vmName, diskLabel, volumePath, overlayPath, marker)) { + return; + } + } + + reconcileOffline(volumePath, overlayPath, marker); + + } catch (IOException e) { + logger.error("Failed to read snapshot marker {}: {}", marker.getName(), e.getMessage()); + } + } + + private boolean reconcileWithRunningDomain(String vmName, String diskLabel, String volumePath, + String overlayPath, File marker) { + try { + Connect conn = LibvirtConnection.getConnection(); + Domain vm = conn.domainLookupByName(vmName); + if (vm == null) { + return false; + } + + String xmlDesc = vm.getXMLDesc(0); + LibvirtDomainXMLParser parser = new LibvirtDomainXMLParser(); + parser.parseDomainXML(xmlDesc); + + for (DiskDef disk : parser.getDisks()) { + String currentSource = disk.getDiskPath(); + if (currentSource != null && currentSource.equals(overlayPath)) { + logger.warn("VM [{}] disk [{}] is still on overlay [{}]. Attempting blockcommit to merge back to base [{}].", + vmName, disk.getDiskLabel(), overlayPath, volumePath); + + String actualDiskLabel = StringUtils.isNotEmpty(diskLabel) ? diskLabel : disk.getDiskLabel(); + try { + resource.mergeDeltaIntoBaseFile(vm, actualDiskLabel, volumePath, null, true, "reconcile", null, conn); + logger.info("Successfully reconciled overlay [{}] back to base [{}] for VM [{}].", overlayPath, volumePath, vmName); + marker.delete(); + return true; + } catch (Exception e) { + logger.error("Failed to blockcommit overlay [{}] for VM [{}]: {}. Manual intervention required.", + overlayPath, vmName, e.getMessage(), e); + return true; + } + } + + if (currentSource != null && currentSource.equals(volumePath)) { + logger.info("VM [{}] disk [{}] is already on base [{}]. Overlay [{}] is orphaned. Removing marker.", + vmName, disk.getDiskLabel(), volumePath, overlayPath); + marker.delete(); + return true; + } + } + + return false; + } catch (LibvirtException e) { + logger.debug("VM [{}] not found or not running: {}. Will attempt offline reconciliation.", vmName, e.getMessage()); + return false; + } + } + + private void reconcileOffline(String volumePath, String overlayPath, File marker) { + File baseFile = new File(volumePath); + File overlayFile = new File(overlayPath); + + if (!overlayFile.exists()) { + logger.info("Overlay [{}] no longer exists. Removing marker.", overlayPath); + marker.delete(); + return; + } + + if (!baseFile.exists()) { + logger.error("Base file [{}] does not exist but overlay [{}] does. Cannot reconcile. Manual intervention required.", volumePath, overlayPath); + return; + } + + long markerTimestamp = 0; + try { + String content = new String(Files.readAllBytes(marker.toPath())).trim(); + String[] parts = content.split("\\|", -1); + if (parts.length > 6) { + markerTimestamp = Long.parseLong(parts[6]); + } + } catch (Exception e) { + logger.debug("Could not parse marker timestamp", e); + } + + if (markerTimestamp > 0 && baseFile.lastModified() > markerTimestamp) { + logger.error("Base file [{}] has been modified since snapshot marker was written (base modified={}, marker={}). " + + "The overlay [{}] cannot be safely committed. Manual intervention required — keeping marker.", + volumePath, baseFile.lastModified(), markerTimestamp, overlayPath); + return; + } + + try { + logger.warn("Attempting offline qemu-img commit of overlay [{}] into base [{}].", overlayPath, volumePath); + String commitCommand = String.format("qemu-img commit %s", overlayPath); + String result = Script.runSimpleBashScript(commitCommand); + if (result != null) { + logger.warn("qemu-img commit output: {}", result); + } + + logger.info("Successfully committed overlay [{}] into base [{}]. Removing marker.", overlayPath, volumePath); + marker.delete(); + + if (overlayFile.exists()) { + overlayFile.delete(); + logger.debug("Deleted orphan overlay file [{}].", overlayPath); + } + } catch (Exception e) { + logger.error("Failed to offline-commit overlay [{}] into base [{}]: {}. Manual intervention required.", + overlayPath, volumePath, e.getMessage(), e); + } + } } diff --git a/utils/src/main/java/com/cloud/utils/script/Script.java b/utils/src/main/java/com/cloud/utils/script/Script.java index 5a92d12eeda9..825774a8c03f 100644 --- a/utils/src/main/java/com/cloud/utils/script/Script.java +++ b/utils/src/main/java/com/cloud/utils/script/Script.java @@ -898,8 +898,11 @@ public static String runSimpleBashScriptWithFullResult(String command, int timeo OutputInterpreter.AllLinesParser parser = new OutputInterpreter.AllLinesParser(); - if (script.execute(parser) != null) { - throw new CloudRuntimeException(String.format("Error executing command [%s]", script)); + String executeResult = script.execute(parser); + if (executeResult != null) { + String output = parser.getLines(); + String errorDetail = (output != null && !output.trim().isEmpty()) ? output.trim() : executeResult; + throw new CloudRuntimeException(String.format("Error executing command [%s]: %s", script, errorDetail)); } return parser.getLines(); } From 5ce4411b22bdd67bdf4dc97ad96c0c92c37176a1 Mon Sep 17 00:00:00 2001 From: Siddharthan P S Date: Fri, 13 Nov 2026 11:14:58 -0500 Subject: [PATCH 2/2] Add unit tests for snapshot overlay fix --- .../test/java/com/cloud/agent/AgentTest.java | 41 ++++ .../kvm/storage/KVMStorageProcessorTest.java | 221 ++++++++++++++++++ .../com/cloud/utils/script/ScriptTest.java | 23 ++ 3 files changed, 285 insertions(+) diff --git a/agent/src/test/java/com/cloud/agent/AgentTest.java b/agent/src/test/java/com/cloud/agent/AgentTest.java index 65dc030ebd76..9822b7bee8cb 100644 --- a/agent/src/test/java/com/cloud/agent/AgentTest.java +++ b/agent/src/test/java/com/cloud/agent/AgentTest.java @@ -22,10 +22,12 @@ import static org.junit.Assert.assertSame; import static org.junit.Assert.assertTrue; import static org.mockito.Mockito.any; +import static org.mockito.Mockito.doNothing; import static org.mockito.Mockito.doReturn; import static org.mockito.Mockito.doThrow; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.eq; +import static org.mockito.Mockito.spy; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; @@ -254,4 +256,43 @@ public void testStopAndCleanupConnectionValidConnectionWaitForStopWaitsForStartu verify(mockConnection).cleanUp(); verify(mockBackoff, times(3)).waitBeforeRetry(); } + + @Test + public void testWaitForCommandsAndReconnectNoCommandsInProgress() throws ConfigurationException { + Agent spyAgent = spy(new Agent(shell, 1, serverResource)); + ReflectionTestUtils.setField(spyAgent, "logger", logger); + doNothing().when(spyAgent).reconnect(any(Link.class)); + + Link mockLink = mock(Link.class); + spyAgent.commandsInProgress.set(0); + spyAgent.waitForCommandsAndReconnect(mockLink); + + verify(spyAgent).reconnect(mockLink); + verify(logger).info(eq("Reconnecting instead of exiting to avoid losing in-flight work (e.g. snapshot overlays).")); + } + + @Test + public void testWaitForCommandsAndReconnectCommandsCompleteBeforeTimeout() throws ConfigurationException { + Agent spyAgent = spy(new Agent(shell, 1, serverResource)); + ReflectionTestUtils.setField(spyAgent, "logger", logger); + doNothing().when(spyAgent).reconnect(any(Link.class)); + + Link mockLink = mock(Link.class); + spyAgent.commandsInProgress.set(1); + + Thread decrementThread = new Thread(() -> { + try { + Thread.sleep(500); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + spyAgent.commandsInProgress.set(0); + }); + decrementThread.start(); + + spyAgent.waitForCommandsAndReconnect(mockLink); + + verify(spyAgent).reconnect(mockLink); + verify(logger).info(eq("All in-progress commands completed. Proceeding with reconnect.")); + } } diff --git a/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessorTest.java b/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessorTest.java index a85fc31224e0..40d9399fe79a 100644 --- a/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessorTest.java +++ b/plugins/hypervisors/kvm/src/test/java/com/cloud/hypervisor/kvm/storage/KVMStorageProcessorTest.java @@ -59,6 +59,7 @@ import javax.naming.ConfigurationException; import java.io.File; +import java.io.FileOutputStream; import java.io.IOException; import java.lang.reflect.Method; import java.nio.file.Files; @@ -68,6 +69,7 @@ import java.util.List; import java.util.Map; import java.util.Set; +import java.util.concurrent.locks.ReentrantLock; @RunWith(MockitoJUnitRunner.class) public class KVMStorageProcessorTest { @@ -765,4 +767,223 @@ public void ensureLibvirtSupportsEncryptedRbdHotplugIgnoresNonRbd() { // version is not even consulted for them. storageProcessor.ensureLibvirtSupportsEncryptedRbdHotplug(StoragePoolType.NetworkFilesystem); } + + private File tempMarkerDir; + + private void setUpMarkerDir() throws Exception { + tempMarkerDir = Files.createTempDirectory("snapshot_markers_test").toFile(); + java.lang.reflect.Field field = KVMStorageProcessor.class.getDeclaredField("SNAPSHOT_MARKER_DIR"); + field.setAccessible(true); + + java.lang.reflect.Field modifiers = java.lang.reflect.Field.class.getDeclaredField("modifiers"); + modifiers.setAccessible(true); + modifiers.setInt(field, field.getModifiers() & ~java.lang.reflect.Modifier.FINAL); + field.set(null, tempMarkerDir.getAbsolutePath()); + } + + private void cleanUpMarkerDir() { + if (tempMarkerDir != null && tempMarkerDir.exists()) { + File[] files = tempMarkerDir.listFiles(); + if (files != null) { + for (File f : files) { + f.delete(); + } + } + tempMarkerDir.delete(); + } + } + + @Test + public void testWriteSnapshotMarkerCreatesFile() throws Exception { + File markerDir = Files.createTempDirectory("marker_test").toFile(); + try { + Mockito.when(kvmStoragePoolMock.getUuid()).thenReturn("pool-uuid-1"); + storageProcessorSpy.writeSnapshotMarker(kvmStoragePoolMock, "/mnt/pool/vol1", "snap1"); + + File[] files = new File("/var/cache/cloudstack/snapshot_markers").listFiles( + (dir, name) -> name.contains("pool-uuid-1") && name.contains("snap1")); + if (files != null && files.length > 0) { + String content = new String(Files.readAllBytes(files[0].toPath())); + Assert.assertTrue(content.contains("pool-uuid-1")); + Assert.assertTrue(content.contains("snap1")); + files[0].delete(); + } + } finally { + markerDir.delete(); + } + } + + @Test + public void testWriteAndRemoveSnapshotMarker() throws Exception { + File markerDir = new File("/tmp/test_snapshot_markers_" + System.currentTimeMillis()); + markerDir.mkdirs(); + try { + java.lang.reflect.Field field = KVMStorageProcessor.class.getDeclaredField("SNAPSHOT_MARKER_DIR"); + field.setAccessible(true); + String originalDir = (String) field.get(null); + + Mockito.when(kvmStoragePoolMock.getUuid()).thenReturn("test-pool"); + + storageProcessorSpy.writeSnapshotMarker(kvmStoragePoolMock, "/mnt/pool/vol", "snap"); + + File[] written = markerDir.listFiles(); + + storageProcessorSpy.removeSnapshotMarker(kvmStoragePoolMock, "/mnt/pool/vol", "snap"); + } finally { + File[] remaining = markerDir.listFiles(); + if (remaining != null) { + for (File f : remaining) f.delete(); + } + markerDir.delete(); + } + } + + @Test + public void testReconcileSnapshotMarkersNoMarkerDir() { + storageProcessorSpy.reconcileSnapshotMarkers(); + } + + @Test + public void testReconcileSingleMarkerOverlayGone() throws Exception { + File tempDir = Files.createTempDirectory("reconcile_test").toFile(); + try { + File marker = new File(tempDir, ".snapshot_marker_test"); + String content = "pool-uuid|/mnt/vol|snap|||| " + System.currentTimeMillis(); + try (FileOutputStream fos = new FileOutputStream(marker)) { + fos.write(content.getBytes()); + } + + Mockito.when(resource.getSnapshotTemporaryPath(Mockito.anyString(), Mockito.anyString())) + .thenReturn("/nonexistent/overlay/path"); + + storageProcessorSpy.reconcileSingleMarker(marker); + + Assert.assertFalse("Marker should be removed when overlay is gone", marker.exists()); + } finally { + File[] files = tempDir.listFiles(); + if (files != null) for (File f : files) f.delete(); + tempDir.delete(); + } + } + + @Test + public void testReconcileSingleMarkerInvalidFormat() throws Exception { + File tempDir = Files.createTempDirectory("reconcile_invalid_test").toFile(); + try { + File marker = new File(tempDir, ".snapshot_marker_invalid"); + try (FileOutputStream fos = new FileOutputStream(marker)) { + fos.write("invalid".getBytes()); + } + + storageProcessorSpy.reconcileSingleMarker(marker); + + Assert.assertTrue("Marker with invalid format should not be deleted", marker.exists()); + } finally { + File[] files = tempDir.listFiles(); + if (files != null) for (File f : files) f.delete(); + tempDir.delete(); + } + } + + @Test + public void testGetVmBlockJobLockReturnsSameLockForSameVm() throws Exception { + java.lang.reflect.Method method = KVMStorageProcessor.class.getDeclaredMethod("getVmBlockJobLock", String.class); + method.setAccessible(true); + + ReentrantLock lock1 = (ReentrantLock) method.invoke(storageProcessorSpy, "vm-1"); + ReentrantLock lock2 = (ReentrantLock) method.invoke(storageProcessorSpy, "vm-1"); + ReentrantLock lock3 = (ReentrantLock) method.invoke(storageProcessorSpy, "vm-2"); + + Assert.assertSame("Same VM should return same lock", lock1, lock2); + Assert.assertNotSame("Different VMs should return different locks", lock1, lock3); + } + + @Test + public void testReconcileOfflineBaseModifiedSinceMarker() throws Exception { + File tempDir = Files.createTempDirectory("reconcile_offline_test").toFile(); + try { + File baseFile = new File(tempDir, "base.qcow2"); + File overlayFile = new File(tempDir, "overlay.qcow2"); + + try (FileOutputStream fos = new FileOutputStream(baseFile)) { fos.write("base".getBytes()); } + try (FileOutputStream fos = new FileOutputStream(overlayFile)) { fos.write("overlay".getBytes()); } + + long markerTimestamp = System.currentTimeMillis() - 60000; + + baseFile.setLastModified(System.currentTimeMillis()); + + File marker = new File(tempDir, ".snapshot_marker_test"); + String content = String.join("|", + "pool-uuid", baseFile.getAbsolutePath(), "snap", "vm1", "vda", + overlayFile.getAbsolutePath(), String.valueOf(markerTimestamp)); + try (FileOutputStream fos = new FileOutputStream(marker)) { + fos.write(content.getBytes()); + } + + java.lang.reflect.Method method = KVMStorageProcessor.class.getDeclaredMethod( + "reconcileOffline", String.class, String.class, File.class); + method.setAccessible(true); + method.invoke(storageProcessorSpy, baseFile.getAbsolutePath(), overlayFile.getAbsolutePath(), marker); + + Assert.assertTrue("Marker should be kept when base was modified after marker", marker.exists()); + } finally { + File[] files = tempDir.listFiles(); + if (files != null) for (File f : files) f.delete(); + tempDir.delete(); + } + } + + @Test + public void testReconcileOfflineBaseDoesNotExist() throws Exception { + File tempDir = Files.createTempDirectory("reconcile_nobase_test").toFile(); + try { + File overlayFile = new File(tempDir, "overlay.qcow2"); + try (FileOutputStream fos = new FileOutputStream(overlayFile)) { fos.write("overlay".getBytes()); } + + File marker = new File(tempDir, ".snapshot_marker_test"); + try (FileOutputStream fos = new FileOutputStream(marker)) { fos.write("marker".getBytes()); } + + java.lang.reflect.Method method = KVMStorageProcessor.class.getDeclaredMethod( + "reconcileOffline", String.class, String.class, File.class); + method.setAccessible(true); + method.invoke(storageProcessorSpy, "/nonexistent/base.qcow2", overlayFile.getAbsolutePath(), marker); + + Assert.assertTrue("Marker should be kept when base does not exist", marker.exists()); + } finally { + File[] files = tempDir.listFiles(); + if (files != null) for (File f : files) f.delete(); + tempDir.delete(); + } + } + + @Test + public void testReconcileOfflineOverlayDoesNotExist() throws Exception { + File tempDir = Files.createTempDirectory("reconcile_nooverlay_test").toFile(); + try { + File marker = new File(tempDir, ".snapshot_marker_test"); + try (FileOutputStream fos = new FileOutputStream(marker)) { fos.write("marker".getBytes()); } + + java.lang.reflect.Method method = KVMStorageProcessor.class.getDeclaredMethod( + "reconcileOffline", String.class, String.class, File.class); + method.setAccessible(true); + method.invoke(storageProcessorSpy, "/some/base.qcow2", "/nonexistent/overlay.qcow2", marker); + + Assert.assertFalse("Marker should be removed when overlay does not exist", marker.exists()); + } finally { + File[] files = tempDir.listFiles(); + if (files != null) for (File f : files) f.delete(); + tempDir.delete(); + } + } + + @Test + public void testUpdateSnapshotMarkerDelegatesToWrite() throws Exception { + Mockito.doNothing().when(storageProcessorSpy).writeSnapshotMarker( + Mockito.any(), Mockito.anyString(), Mockito.anyString(), + Mockito.anyString(), Mockito.anyString(), Mockito.anyString()); + + storageProcessorSpy.updateSnapshotMarker(kvmStoragePoolMock, "/vol", "snap", "vm", "vda", "/overlay"); + + Mockito.verify(storageProcessorSpy).writeSnapshotMarker(kvmStoragePoolMock, "/vol", "snap", "vm", "vda", "/overlay"); + } } diff --git a/utils/src/test/java/com/cloud/utils/script/ScriptTest.java b/utils/src/test/java/com/cloud/utils/script/ScriptTest.java index a52f3840bea9..1b009e50cf45 100644 --- a/utils/src/test/java/com/cloud/utils/script/ScriptTest.java +++ b/utils/src/test/java/com/cloud/utils/script/ScriptTest.java @@ -28,6 +28,7 @@ import org.mockito.junit.MockitoJUnitRunner; import com.cloud.utils.Pair; +import com.cloud.utils.exception.CloudRuntimeException; @RunWith(MockitoJUnitRunner.class) public class ScriptTest { @@ -108,4 +109,26 @@ public void testBuildCommandLineWithLegacyPasswordOption() { Assert.assertEquals("test.sh -y ****** ", commandLine); } + @Test + public void testRunSimpleBashScriptWithFullResultSuccess() { + String result = Script.runSimpleBashScriptWithFullResult("echo hello", 10); + Assert.assertNotNull(result); + Assert.assertEquals("hello", result.trim()); + } + + @Test(expected = CloudRuntimeException.class) + public void testRunSimpleBashScriptWithFullResultFailureIncludesOutput() { + try { + Script.runSimpleBashScriptWithFullResult("echo 'some error detail' >&2; exit 1", 10); + } catch (CloudRuntimeException e) { + Assert.assertTrue(e.getMessage().contains("Error executing command")); + throw e; + } + } + + @Test(expected = CloudRuntimeException.class) + public void testRunSimpleBashScriptWithFullResultFailureOnInvalidCommand() { + Script.runSimpleBashScriptWithFullResult("nonexistent_command_xyz_12345", 10); + } + }