Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@cloudstack.apache.org
Date: Tue, 10 Dec 2013 19:42:07 +0000 (UTC)
From: "Prachi Damle (JIRA)" <jira@apache.org>
To: cloudstack-issues@incubator.apache.org
Message-ID: <JIRA.12682995.1386276713315.11646.1386704527263@arcas>
In-Reply-To: <JIRA.12682995.1386276713315@arcas>
References: <JIRA.12682995.1386276713315@arcas>
Subject: [jira] [Commented] (CLOUDSTACK-5389) [Automation] Race Condition :
 Failed to find storage pool during router deployment in KVM
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


    [ https://issues.apache.org/jira/browse/CLOUDSTACK-5389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13844590#comment-13844590 ] 

Prachi Damle commented on CLOUDSTACK-5389:
------------------------------------------

Looking at the logs, I dont think this is related to any KVM issue or is a race condition either.

The failure happens because the deployment is trying to look for storage pools with a certain tag. Confirmed with Rayees, that the storage pools do not bear any tags, So given these logs, the VM deployment failure looks as expected.


2013-12-05 10:10:36,275 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) We need to allocate new storagepool for this volume
2013-12-05 10:10:36,277 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Calling StoragePoolAllocators to find suitable pools
2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) ClusterScopeStoragePoolAllocator looking for storage pool
2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Looking for pools in dc: 1  pod:1  cluster:1 having tags:[host1]
2013-12-05 10:10:36,282 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No storage pools available for shared volume allocation, returning
2013-12-05 10:10:36,287 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) List of pools in ascending order of number of volumes for account id: 683 is: [1, 4, 2]
2013-12-05 10:10:36,287 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) ZoneWideStoragePoolAllocator to find storage pool
2013-12-05 10:10:36,290 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) List of pools in ascending order of number of volumes for account id: 683 is: []
2013-12-05 10:10:36,290 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable pools found for volume: Vol[1291|vm=1179|ROOT] under cluster: 1
2013-12-05 10:10:36,290 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable pools found
2013-12-05 10:10:36,291 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable storagePools found under this Cluster: 1
2013-12-05 10:10:36,294 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Could not find suitable Deployment Destination for this VM under any clusters, returning.

> [Automation] Race Condition : Failed to find storage pool during router deployment in KVM
> -----------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-5389
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5389
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Management Server
>    Affects Versions: 4.3.0
>         Environment: Branch : 4.3
> Environment : KVM (RHEL 6.3) 
>            Reporter: Rayees Namathponnan
>            Assignee: Prachi Damle
>            Priority: Critical
>             Fix For: 4.3.0
>
>         Attachments: Agent1.rar, Agent2.rar, Mslog.rar
>
>
> This issue is observed during automation run;  6 test cases cases are executing in parallel in automation environment;  random deployment failure observed during automation run due to "No suitable storagePools found under this Cluster: 1"
> 2 primary storages are already configured in zone1; it as enough space too 
> observed below error in ms log
> 2013-12-05 10:10:36,274 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8 FirstFitRoutingAllocator) Found a suitable host, adding to list: 2
> 2013-12-05 10:10:36,274 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8 FirstFitRoutingAllocator) Host Allocator returning 2 suitable hosts
> 2013-12-05 10:10:36,275 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Checking suitable pools for volume (Id, Type): (1291,ROOT)
> 2013-12-05 10:10:36,275 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) We need to allocate new storagepool for this volume
> 2013-12-05 10:10:36,277 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Calling StoragePoolAllocators to find suitable pools
> 2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) ClusterScopeStoragePoolAllocator looking for storage pool
> 2013-12-05 10:10:36,278 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Looking for pools in dc: 1  pod:1  cluster:1 having tags:[host1]
> 2013-12-05 10:10:36,282 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No storage pools available for shared volume allocation, returning
> 2013-12-05 10:10:36,287 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) List of pools in ascending order of number of volumes for account id: 683 is: [1, 4, 2]
> 2013-12-05 10:10:36,287 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) ZoneWideStoragePoolAllocator to find storage pool
> 2013-12-05 10:10:36,290 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) List of pools in ascending order of number of volumes for account id: 683 is: []
> 2013-12-05 10:10:36,290 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable pools found for volume: Vol[1291|vm=1179|ROOT] under cluster: 1
> 2013-12-05 10:10:36,290 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable pools found
> 2013-12-05 10:10:36,291 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No suitable storagePools found under this Cluster: 1
> 2013-12-05 10:10:36,294 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> 2013-12-05 10:10:36,294 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Searching all possible resources under this Zone: 1
> 2013-12-05 10:10:36,295 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2013-12-05 10:10:36,298 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Removing from the clusterId list these clusters from avoid set: [1]
> 2013-12-05 10:10:36,300 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) No clusters found after removing disabled clusters and clusters in avoid list, returning.
> 2013-12-05 10:10:36,303 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Destroying vm VM[User|QA-35aa7053-f3d7-4b16-86d3-487bcce7c9bb] as it failed to create on Host with Id:null
> 2013-12-05 10:10:36,325 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
> 2013-12-05 10:10:36,347 WARN  [o.a.c.alerts] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 1179, on Host with Id: null
> 2013-12-05 10:10:36,383 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|QA-35aa7053-f3d7-4b16-86d3-487bcce7c9bb]Scope=interface com.cloud.dc.DataCenter; id=1
> 2013-12-05 10:10:36,383 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-98:ctx-fe814e55 ctx-e2685be8) Unable to create a deployment for VM[User|QA-35aa7053-f3d7-4b16-86d3-487bcce7c9bb]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|QA-35aa7053-f3d7-4b16-86d3-487bcce7c9bb]Scope=interface com.cloud.dc.DataCenter; id=1
>         at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
>         at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3542)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3124)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3110)
>         at sun.reflect.GeneratedMethodAccessor518.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:616)
>   


--
This message was sent by Atlassian JIRA
(v6.1.4#6159)