From 1bda2343f3590f82e8a00e5b0aa1c5fb51e9f108 Mon Sep 17 00:00:00 2001 From: SadiJr Date: Thu, 28 Sep 2023 08:42:42 -0300 Subject: [PATCH] Improve logs when searching one storage pool to allocate a new volume (#7212) Co-authored-by: SadiJr --- .../AbstractStoragePoolAllocator.java | 17 +++++++++-------- .../ClusterScopeStoragePoolAllocator.java | 3 ++- .../allocator/LocalStoragePoolAllocator.java | 5 ++++- .../ZoneWideStoragePoolAllocator.java | 3 ++- .../com/cloud/storage/StorageManagerImpl.java | 19 ++++++++++++++----- 5 files changed, 31 insertions(+), 16 deletions(-) diff --git a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/AbstractStoragePoolAllocator.java b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/AbstractStoragePoolAllocator.java index 2966f682048..f2b0f17232b 100644 --- a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/AbstractStoragePoolAllocator.java +++ b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/AbstractStoragePoolAllocator.java @@ -263,13 +263,9 @@ public abstract class AbstractStoragePoolAllocator extends AdapterBase implement } protected boolean filter(ExcludeList avoid, StoragePool pool, DiskProfile dskCh, DeploymentPlan plan) { - if (s_logger.isDebugEnabled()) { - s_logger.debug("Checking if storage pool is suitable, name: " + pool.getName() + " ,poolId: " + pool.getId()); - } + s_logger.debug(String.format("Checking if storage pool [%s] is suitable to disk [%s].", pool, dskCh)); if (avoid.shouldAvoid(pool)) { - if (s_logger.isDebugEnabled()) { - s_logger.debug("StoragePool is in avoid set, skipping this pool"); - } + s_logger.debug(String.format("StoragePool [%s] is in avoid set, skipping this pool to allocation of disk [%s].", pool, dskCh)); return false; } @@ -297,6 +293,8 @@ public abstract class AbstractStoragePoolAllocator extends AdapterBase implement } if (!checkDiskProvisioningSupport(dskCh, pool)) { + s_logger.debug(String.format("Storage pool [%s] does not have support to disk provisioning of disk [%s].", pool, ReflectionToStringBuilderUtils.reflectOnlySelectedFields(dskCh, + "type", "name", "diskOfferingId", "templateId", "volumeId", "provisioningType", "hyperType"))); return false; } @@ -306,10 +304,12 @@ public abstract class AbstractStoragePoolAllocator extends AdapterBase implement Volume volume = volumeDao.findById(dskCh.getVolumeId()); if(!storageMgr.storagePoolCompatibleWithVolumePool(pool, volume)) { + s_logger.debug(String.format("Pool [%s] is not compatible with volume [%s], skipping it.", pool, volume)); return false; } if (pool.isManaged() && !storageUtil.managedStoragePoolCanScale(pool, plan.getClusterId(), plan.getHostId())) { + s_logger.debug(String.format("Cannot allocate pool [%s] to volume [%s] because the max number of managed clustered filesystems has been exceeded.", pool, volume)); return false; } @@ -317,14 +317,14 @@ public abstract class AbstractStoragePoolAllocator extends AdapterBase implement List> requestVolumeDiskProfilePairs = new ArrayList<>(); requestVolumeDiskProfilePairs.add(new Pair<>(volume, dskCh)); if (dskCh.getHypervisorType() == HypervisorType.VMware) { - // Skip the parent datastore cluster, consider only child storage pools in it if (pool.getPoolType() == Storage.StoragePoolType.DatastoreCluster && storageMgr.isStoragePoolDatastoreClusterParent(pool)) { + s_logger.debug(String.format("Skipping allocation of pool [%s] to volume [%s] because this pool is a parent datastore cluster.", pool, volume)); return false; } - // Skip the storage pool whose parent datastore cluster is not in UP state. if (pool.getParent() != 0L) { StoragePoolVO datastoreCluster = storagePoolDao.findById(pool.getParent()); if (datastoreCluster == null || (datastoreCluster != null && datastoreCluster.getStatus() != StoragePoolStatus.Up)) { + s_logger.debug(String.format("Skipping allocation of pool [%s] to volume [%s] because this pool is not in [%s] state.", datastoreCluster, volume, StoragePoolStatus.Up)); return false; } } @@ -332,6 +332,7 @@ public abstract class AbstractStoragePoolAllocator extends AdapterBase implement try { boolean isStoragePoolStoragepolicyComplaince = storageMgr.isStoragePoolCompliantWithStoragePolicy(requestVolumeDiskProfilePairs, pool); if (!isStoragePoolStoragepolicyComplaince) { + s_logger.debug(String.format("Skipping allocation of pool [%s] to volume [%s] because this pool is not compliant with the storage policy required by the volume.", pool, volume)); return false; } } catch (StorageUnavailableException e) { diff --git a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ClusterScopeStoragePoolAllocator.java b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ClusterScopeStoragePoolAllocator.java index e7c9b7e6f3d..fe49504fda1 100644 --- a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ClusterScopeStoragePoolAllocator.java +++ b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ClusterScopeStoragePoolAllocator.java @@ -100,9 +100,10 @@ public class ClusterScopeStoragePoolAllocator extends AbstractStoragePoolAllocat } StoragePool storagePool = (StoragePool)dataStoreMgr.getPrimaryDataStore(pool.getId()); if (filter(avoid, storagePool, dskCh, plan)) { - s_logger.trace(String.format("Found suitable local storage pool [%s], adding to list.", pool)); + s_logger.debug(String.format("Found suitable local storage pool [%s] to allocate disk [%s] to it, adding to list.", pool, dskCh)); suitablePools.add(storagePool); } else { + s_logger.debug(String.format("Adding storage pool [%s] to avoid set during allocation of disk [%s].", pool, dskCh)); avoid.addPool(pool.getId()); } } diff --git a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/LocalStoragePoolAllocator.java b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/LocalStoragePoolAllocator.java index 4fbaa8c0e83..774c2229a09 100644 --- a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/LocalStoragePoolAllocator.java +++ b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/LocalStoragePoolAllocator.java @@ -82,9 +82,10 @@ public class LocalStoragePoolAllocator extends AbstractStoragePoolAllocator { if (pool != null && pool.isLocal()) { StoragePool storagePool = (StoragePool)this.dataStoreMgr.getPrimaryDataStore(pool.getId()); if (filter(avoid, storagePool, dskCh, plan)) { - s_logger.trace(String.format("Found suitable local storage pool [%s], adding to list.", pool)); + s_logger.debug(String.format("Found suitable local storage pool [%s] to allocate disk [%s] to it, adding to list.", pool, dskCh)); suitablePools.add(storagePool); } else { + s_logger.debug(String.format("Adding storage pool [%s] to avoid set during allocation of disk [%s].", pool, dskCh)); avoid.addPool(pool.getId()); } } @@ -107,8 +108,10 @@ public class LocalStoragePoolAllocator extends AbstractStoragePoolAllocator { } StoragePool storagePool = (StoragePool)this.dataStoreMgr.getPrimaryDataStore(pool.getId()); if (filter(avoid, storagePool, dskCh, plan)) { + s_logger.debug(String.format("Found suitable local storage pool [%s] to allocate disk [%s] to it, adding to list.", pool, dskCh)); suitablePools.add(storagePool); } else { + s_logger.debug(String.format("Adding storage pool [%s] to avoid set during allocation of disk [%s].", pool, dskCh)); avoid.addPool(pool.getId()); } } diff --git a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ZoneWideStoragePoolAllocator.java b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ZoneWideStoragePoolAllocator.java index 2902871a9eb..1b3835560df 100644 --- a/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ZoneWideStoragePoolAllocator.java +++ b/engine/storage/src/main/java/org/apache/cloudstack/storage/allocator/ZoneWideStoragePoolAllocator.java @@ -94,10 +94,11 @@ public class ZoneWideStoragePoolAllocator extends AbstractStoragePoolAllocator { } StoragePool storagePool = (StoragePool)this.dataStoreMgr.getPrimaryDataStore(storage.getId()); if (filter(avoid, storagePool, dskCh, plan)) { - LOGGER.trace(String.format("Found suitable local storage pool [%s], adding to list.", storage)); + LOGGER.debug(String.format("Found suitable local storage pool [%s] to allocate disk [%s] to it, adding to list.", storagePool, dskCh)); suitablePools.add(storagePool); } else { if (canAddStoragePoolToAvoidSet(storage)) { + LOGGER.debug(String.format("Adding storage pool [%s] to avoid set during allocation of disk [%s].", storagePool, dskCh)); avoid.addPool(storagePool.getId()); } } diff --git a/server/src/main/java/com/cloud/storage/StorageManagerImpl.java b/server/src/main/java/com/cloud/storage/StorageManagerImpl.java index f4331aa5041..4bdb8f2861e 100644 --- a/server/src/main/java/com/cloud/storage/StorageManagerImpl.java +++ b/server/src/main/java/com/cloud/storage/StorageManagerImpl.java @@ -2388,6 +2388,7 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C @Override public boolean storagePoolHasEnoughIops(List> requestedVolumes, StoragePool pool) { if (requestedVolumes == null || requestedVolumes.isEmpty() || pool == null) { + s_logger.debug(String.format("Cannot check if storage [%s] has enough IOPS to allocate volumes [%s].", pool, requestedVolumes)); return false; } @@ -2418,8 +2419,10 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C } long futureIops = currentIops + requestedIops; - - return futureIops <= pool.getCapacityIops(); + boolean hasEnoughIops = futureIops <= pool.getCapacityIops(); + String hasCapacity = hasEnoughIops ? "has" : "does not have"; + s_logger.debug(String.format("Pool [%s] %s enough IOPS to allocate volumes [%s].", pool, hasCapacity, requestedVolumes)); + return hasEnoughIops; } @Override @@ -2430,10 +2433,12 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C @Override public boolean storagePoolHasEnoughSpace(List> volumeDiskProfilesList, StoragePool pool, Long clusterId) { if (CollectionUtils.isEmpty(volumeDiskProfilesList)) { + s_logger.debug(String.format("Cannot check if pool [%s] has enough space to allocate volumes because the volumes list is empty.", pool)); return false; } if (!checkUsagedSpace(pool)) { + s_logger.debug(String.format("Cannot allocate pool [%s] because there is not enough space in this pool.", pool)); return false; } @@ -2696,30 +2701,34 @@ public class StorageManagerImpl extends ManagerBase implements StorageManager, C @Override public boolean storagePoolCompatibleWithVolumePool(StoragePool pool, Volume volume) { if (pool == null || volume == null) { + s_logger.debug(String.format("Cannot check if storage pool [%s] is compatible with volume [%s].", pool, volume)); return false; } if (volume.getPoolId() == null) { - // Volume is not allocated to any pool. Not possible to check compatibility with other pool, let it try + s_logger.debug(String.format("Volume [%s] is not allocated to any pool. Cannot check compatibility with pool [%s].", volume, pool)); return true; } StoragePool volumePool = _storagePoolDao.findById(volume.getPoolId()); if (volumePool == null) { - // Volume pool doesn't exist. Not possible to check compatibility with other pool, let it try + s_logger.debug(String.format("Pool [%s] used by volume [%s] does not exist. Cannot check compatibility.", pool, volume)); return true; } if (volume.getState() == Volume.State.Ready) { if (volumePool.getPoolType() == Storage.StoragePoolType.PowerFlex && pool.getPoolType() != Storage.StoragePoolType.PowerFlex) { + s_logger.debug(String.format("Pool [%s] with type [%s] does not match volume [%s] pool type [%s].", pool, pool.getPoolType(), volume, volumePool.getPoolType())); return false; } else if (volumePool.getPoolType() != Storage.StoragePoolType.PowerFlex && pool.getPoolType() == Storage.StoragePoolType.PowerFlex) { + s_logger.debug(String.format("Pool [%s] with type [%s] does not match volume [%s] pool type [%s].", pool, pool.getPoolType(), volume, volumePool.getPoolType())); return false; } } else { + s_logger.debug(String.format("Cannot check compatibility of pool [%s] because volume [%s] is not in [%s] state.", pool, volume, Volume.State.Ready)); return false; } - + s_logger.debug(String.format("Pool [%s] is compatible with volume [%s].", pool, volume)); return true; }