From e437d1016f6f44344e0ece563c6e42c71964fd80 Mon Sep 17 00:00:00 2001 From: sato03 Date: Mon, 16 Oct 2023 11:20:09 -0300 Subject: [PATCH] Snapshot removal and storage cleanup logs (#8031) --- .../storage/snapshot/SnapshotServiceImpl.java | 14 ++-- .../com/cloud/storage/StorageManagerImpl.java | 77 ++++++++++++++----- 2 files changed, 63 insertions(+), 28 deletions(-) diff --git a/engine/storage/snapshot/src/main/java/org/apache/cloudstack/storage/snapshot/SnapshotServiceImpl.java b/engine/storage/snapshot/src/main/java/org/apache/cloudstack/storage/snapshot/SnapshotServiceImpl.java index 4d106f5c4f6..0c65eb04533 100644 --- a/engine/storage/snapshot/src/main/java/org/apache/cloudstack/storage/snapshot/SnapshotServiceImpl.java +++ b/engine/storage/snapshot/src/main/java/org/apache/cloudstack/storage/snapshot/SnapshotServiceImpl.java @@ -364,7 +364,7 @@ public class SnapshotServiceImpl implements SnapshotService { SnapshotResult res = null; try { if (result.isFailed()) { - s_logger.debug("delete snapshot failed" + result.getResult()); + s_logger.debug(String.format("Failed to delete snapshot [%s] due to: [%s].", snapshot.getUuid(), result.getResult())); snapshot.processEvent(ObjectInDataStoreStateMachine.Event.OperationFailed); res = new SnapshotResult(context.snapshot, null); res.setResult(result.getResult()); @@ -373,7 +373,8 @@ public class SnapshotServiceImpl implements SnapshotService { res = new SnapshotResult(context.snapshot, null); } } catch (Exception e) { - s_logger.debug("Failed to in deleteSnapshotCallback", e); + s_logger.error(String.format("An exception occurred while processing an event in delete snapshot callback from snapshot [%s].", snapshot.getUuid())); + s_logger.debug(String.format("Exception while processing an event in delete snapshot callback from snapshot [%s].", snapshot.getUuid()), e); res.setResult(e.toString()); } future.complete(res); @@ -418,15 +419,14 @@ public class SnapshotServiceImpl implements SnapshotService { if (result.isFailed()) { throw new CloudRuntimeException(result.getResult()); } + s_logger.debug(String.format("Successfully deleted snapshot [%s] with ID [%s].", snapInfo.getName(), snapInfo.getUuid())); return true; - } catch (InterruptedException e) { - s_logger.debug("delete snapshot is failed: " + e.toString()); - } catch (ExecutionException e) { - s_logger.debug("delete snapshot is failed: " + e.toString()); + } catch (InterruptedException | ExecutionException e) { + s_logger.error(String.format("Failed to delete snapshot [%s] due to: [%s].", snapInfo.getUuid(), e.getMessage())); + s_logger.debug(String.format("Failed to delete snapshot [%s].", snapInfo.getUuid()), e); } return false; - } @Override diff --git a/server/src/main/java/com/cloud/storage/StorageManagerImpl.java b/server/src/main/java/com/cloud/storage/StorageManagerImpl.java index 4bdb8f2861e..56b028720d2 100644 --- a/server/src/main/java/com/cloud/storage/StorageManagerImpl.java +++ b/server/src/main/java/com/cloud/storage/StorageManagerImpl.java @@ -1289,26 +1289,27 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C try { List unusedTemplatesInPool = _tmpltMgr.getUnusedTemplatesInPool(pool); - s_logger.debug("Storage pool garbage collector found " + unusedTemplatesInPool.size() + " templates to clean up in storage pool: " + pool.getName()); + s_logger.debug(String.format("Storage pool garbage collector found [%s] templates to be cleaned up in storage pool [%s].", unusedTemplatesInPool.size(), pool.getName())); for (VMTemplateStoragePoolVO templatePoolVO : unusedTemplatesInPool) { if (templatePoolVO.getDownloadState() != VMTemplateStorageResourceAssoc.Status.DOWNLOADED) { - s_logger.debug("Storage pool garbage collector is skipping template with ID: " + templatePoolVO.getTemplateId() + " on pool " + templatePoolVO.getPoolId() - + " because it is not completely downloaded."); + s_logger.debug(String.format("Storage pool garbage collector is skipping template [%s] clean up on pool [%s] " + + "because it is not completely downloaded.", templatePoolVO.getTemplateId(), templatePoolVO.getPoolId())); continue; } if (!templatePoolVO.getMarkedForGC()) { templatePoolVO.setMarkedForGC(true); _vmTemplatePoolDao.update(templatePoolVO.getId(), templatePoolVO); - s_logger.debug("Storage pool garbage collector has marked template with ID: " + templatePoolVO.getTemplateId() + " on pool " + templatePoolVO.getPoolId() - + " for garbage collection."); + s_logger.debug(String.format("Storage pool garbage collector has marked template [%s] on pool [%s] " + + "for garbage collection.", templatePoolVO.getTemplateId(), templatePoolVO.getPoolId())); continue; } _tmpltMgr.evictTemplateFromStoragePool(templatePoolVO); } } catch (Exception e) { - s_logger.warn("Problem cleaning up primary storage pool " + pool, e); + s_logger.error(String.format("Failed to clean up primary storage pool [%s] due to: [%s].", pool, e.getMessage())); + s_logger.debug(String.format("Failed to clean up primary storage pool [%s].", pool), e); } } } @@ -1316,10 +1317,39 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C //destroy snapshots in destroying state in snapshot_store_ref List ssSnapshots = _snapshotStoreDao.listByState(ObjectInDataStoreStateMachine.State.Destroying); for (SnapshotDataStoreVO ssSnapshotVO : ssSnapshots) { + String snapshotUuid = null; + SnapshotVO snapshot = null; + + if (s_logger.isDebugEnabled()) { + snapshot = _snapshotDao.findById(ssSnapshotVO.getSnapshotId()); + if (snapshot == null) { + s_logger.warn(String.format("Did not find snapshot [%s] in destroying state; therefore, it cannot be destroyed.", ssSnapshotVO.getSnapshotId())); + continue; + } + + snapshotUuid = snapshot.getUuid(); + } + try { - _snapshotService.deleteSnapshot(snapshotFactory.getSnapshot(ssSnapshotVO.getSnapshotId(), DataStoreRole.Image)); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Verifying if snapshot [%s] is in destroying state in any image data store.", snapshotUuid)); + } + + SnapshotInfo snapshotInfo = snapshotFactory.getSnapshot(ssSnapshotVO.getSnapshotId(), DataStoreRole.Image); + + if (snapshotInfo != null) { + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Snapshot [%s] in destroying state found in image data store [%s]; therefore, it will be destroyed.", snapshotUuid, snapshotInfo.getDataStore().getUuid())); + } + _snapshotService.deleteSnapshot(snapshotInfo); + } else if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Did not find snapshot [%s] in destroying state in any image data store.", snapshotUuid)); + } } catch (Exception e) { - s_logger.debug("Failed to delete snapshot: " + ssSnapshotVO.getId() + " from storage"); + s_logger.error(String.format("Failed to delete snapshot [%s] from storage due to: [%s].", ssSnapshotVO.getSnapshotId(), e.getMessage())); + if (s_logger.isDebugEnabled()) { + s_logger.debug(String.format("Failed to delete snapshot [%s] from storage.", snapshotUuid), e); + } } } cleanupSecondaryStorage(recurring); @@ -1343,7 +1373,8 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C // system, but not necessary. handleManagedStorage(vol); } catch (Exception e) { - s_logger.warn("Unable to destroy host-side clustered file system " + vol.getUuid(), e); + s_logger.error(String.format("Unable to destroy host-side clustered file system [%s] due to: [%s].", vol.getUuid(), e.getMessage())); + s_logger.debug(String.format("Unable to destroy host-side clustered file system [%s].", vol.getUuid()), e); } try { @@ -1352,10 +1383,11 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C volService.ensureVolumeIsExpungeReady(vol.getId()); volService.expungeVolumeAsync(volumeInfo); } else { - s_logger.debug("Volume " + vol.getUuid() + " is already destroyed"); + s_logger.debug(String.format("Volume [%s] is already destroyed.", vol.getUuid())); } } catch (Exception e) { - s_logger.warn("Unable to destroy volume " + vol.getUuid(), e); + s_logger.error(String.format("Unable to destroy volume [%s] due to: [%s].", vol.getUuid(), e.getMessage())); + s_logger.debug(String.format("Unable to destroy volume [%s].", vol.getUuid()), e); } } @@ -1369,7 +1401,8 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C } _snapshotDao.expunge(snapshotVO.getId()); } catch (Exception e) { - s_logger.warn("Unable to destroy snapshot " + snapshotVO.getUuid(), e); + s_logger.error(String.format("Unable to destroy snapshot [%s] due to: [%s].", snapshotVO.getUuid(), e.getMessage())); + s_logger.debug(String.format("Unable to destroy snapshot [%s].", snapshotVO.getUuid()), e); } } @@ -1378,14 +1411,14 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C for (VolumeDataStoreVO volumeDataStore : volumeDataStores) { VolumeVO volume = volumeDao.findById(volumeDataStore.getVolumeId()); if (volume == null) { - s_logger.warn("Uploaded volume with id " + volumeDataStore.getVolumeId() + " not found, so cannot be destroyed"); + s_logger.warn(String.format("Uploaded volume [%s] not found, so cannot be destroyed.", volumeDataStore.getVolumeId())); continue; } try { DataStore dataStore = _dataStoreMgr.getDataStore(volumeDataStore.getDataStoreId(), DataStoreRole.Image); EndPoint ep = _epSelector.select(dataStore, volumeDataStore.getExtractUrl()); if (ep == null) { - s_logger.warn("There is no secondary storage VM for image store " + dataStore.getName() + ", cannot destroy uploaded volume " + volume.getUuid()); + s_logger.warn(String.format("There is no secondary storage VM for image store [%s], cannot destroy uploaded volume [%s].", dataStore.getName(), volume.getUuid())); continue; } Host host = _hostDao.findById(ep.getId()); @@ -1397,17 +1430,18 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C // expunge volume from secondary if volume is on image store VolumeInfo volOnSecondary = volFactory.getVolume(volume.getId(), DataStoreRole.Image); if (volOnSecondary != null) { - s_logger.info("Expunging volume " + volume.getUuid() + " uploaded using HTTP POST from secondary data store"); + s_logger.info(String.format("Expunging volume [%s] uploaded using HTTP POST from secondary data store.", volume.getUuid())); AsyncCallFuture future = volService.expungeVolumeAsync(volOnSecondary); VolumeApiResult result = future.get(); if (!result.isSuccess()) { - s_logger.warn("Failed to expunge volume " + volume.getUuid() + " from the image store " + dataStore.getName() + " due to: " + result.getResult()); + s_logger.warn(String.format("Failed to expunge volume [%s] from the image store [%s] due to: [%s].", volume.getUuid(), dataStore.getName(), result.getResult())); } } } } } catch (Throwable th) { - s_logger.warn("Unable to destroy uploaded volume " + volume.getUuid() + ". Error details: " + th.getMessage()); + s_logger.error(String.format("Unable to destroy uploaded volume [%s] due to: [%s].", volume.getUuid(), th.getMessage())); + s_logger.debug(String.format("Unable to destroy uploaded volume [%s].", volume.getUuid()), th); } } @@ -1416,14 +1450,14 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C for (TemplateDataStoreVO templateDataStore : templateDataStores) { VMTemplateVO template = _templateDao.findById(templateDataStore.getTemplateId()); if (template == null) { - s_logger.warn("Uploaded template with id " + templateDataStore.getTemplateId() + " not found, so cannot be destroyed"); + s_logger.warn(String.format("Uploaded template [%s] not found, so cannot be destroyed.", templateDataStore.getTemplateId())); continue; } try { DataStore dataStore = _dataStoreMgr.getDataStore(templateDataStore.getDataStoreId(), DataStoreRole.Image); EndPoint ep = _epSelector.select(dataStore, templateDataStore.getExtractUrl()); if (ep == null) { - s_logger.warn("There is no secondary storage VM for image store " + dataStore.getName() + ", cannot destroy uploaded template " + template.getUuid()); + s_logger.warn(String.format("Cannot destroy uploaded template [%s] as there is no secondary storage VM for image store [%s].", template.getUuid(), dataStore.getName())); continue; } Host host = _hostDao.findById(ep.getId()); @@ -1432,7 +1466,7 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C AsyncCallFuture future = _imageSrv.deleteTemplateAsync(tmplFactory.getTemplate(template.getId(), dataStore)); TemplateApiResult result = future.get(); if (!result.isSuccess()) { - s_logger.warn("Failed to delete template " + template.getUuid() + " from the image store " + dataStore.getName() + " due to: " + result.getResult()); + s_logger.warn(String.format("Failed to delete template [%s] from image store [%s] due to: [%s]", template.getUuid(), dataStore.getName(), result.getResult())); continue; } // remove from template_zone_ref @@ -1456,7 +1490,8 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C } } } catch (Throwable th) { - s_logger.warn("Unable to destroy uploaded template " + template.getUuid() + ". Error details: " + th.getMessage()); + s_logger.error(String.format("Unable to destroy uploaded template [%s] due to: [%s].", template.getUuid(), th.getMessage())); + s_logger.debug(String.format("Unable to destroy uploaded template [%s].", template.getUuid()), th); } } cleanupInactiveTemplates();