Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 0D3C710F72 for ; Thu, 7 Nov 2013 23:19:20 +0000 (UTC) Received: (qmail 2357 invoked by uid 500); 7 Nov 2013 23:19:18 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 2328 invoked by uid 500); 7 Nov 2013 23:19:18 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 2291 invoked by uid 500); 7 Nov 2013 23:19:18 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 2275 invoked by uid 99); 7 Nov 2013 23:19:18 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 07 Nov 2013 23:19:18 +0000 Date: Thu, 7 Nov 2013 23:19:18 +0000 (UTC) From: "Chandan Purushothama (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-5090) Anti-Affinity: VM fails to start on a cluster belonging to a different pod. MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-5090?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Chandan Purushothama updated CLOUDSTACK-5090: --------------------------------------------- Attachment: mysql_cloudstack_db_dumps.zip > Anti-Affinity: VM fails to start on a cluster belonging to a different pod. > --------------------------------------------------------------------------- > > Key: CLOUDSTACK-5090 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5090 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the default.) > Components: Management Server > Affects Versions: 4.2.1 > Reporter: Chandan Purushothama > Fix For: 4.2.1 > > Attachments: mysql_cloudstack_db_dumps.zip > > > Test scenario: > Set up have 3 clusters with 1 host each. One of the cluster's belong to a different pod: > 1.As regular user - U1 , Create multiple anti-affinity group. > 2. Deploy 2 Vms , say Vm11(host1) and VM12(host2) using affinity group A1. > 3. Deploy 1 Vm , say Vm21(host1) using affinity group A2. > 4. Stop Vm11. > 5. Update the list of affinityGroups for this VM to "A1" and "A2" > 6. Start the VM. > =========== > Start VM Job: > =========== > 2013-11-07 14:43:15,755 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-7:null) submit async job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ], details: AsyncJobVO {id:40, userId: 3, accountId: 3, sessionKey: null, instanceType: VirtualMachine, instanceId: 9, cmd: org.apache.cloudstack.api.command.user.vm.StartVMCmd, cmdOriginator: null, cmdInfo: {"response":"json","id":"02e909e8-f28f-40b7-9830-ea68e44aa0ed","sessionkey":"Xj52fOTZWqAUf0nnCSUZlybSVfI\u003d","cmdEventType":"VM.START","ctxUserId":"3","httpmethod":"GET","_":"1383864701141","ctxAccountId":"3","ctxStartEventId":"138"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 7471666038533, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} > 2013-11-07 14:43:15,756 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END=== 10.214.4.75 -- GET command=startVirtualMachine&id=02e909e8-f28f-40b7-9830-ea68e44aa0ed&response=json&sessionkey=Xj52fOTZWqAUf0nnCSUZlybSVfI%3D&_=1383864701141 > 2013-11-07 14:43:15,758 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Executing org.apache.cloudstack.api.command.user.vm.StartVMCmd for job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] > 2013-11-07 14:43:15,774 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Access to VM[User|TestVM-1] granted to Acct[609f0727-6b59-45aa-9bc2-14877b39b4e1-test] by DomainChecker_EnhancerByCloudStack_a4e5904f > 2013-11-07 14:43:15,784 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Service SecurityGroup is not supported in the network id=205 > 2013-11-07 14:43:15,788 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Service SecurityGroup is not supported in the network id=205 > 2013-11-07 14:43:15,811 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A1 for VM Id: 9 > 2013-11-07 14:43:15,813 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 1 to avoid set, since VM 11 is present on the host > 2013-11-07 14:43:15,814 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A2 for VM Id: 9 > 2013-11-07 14:43:15,816 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 6 to avoid set, since VM 12 is present on the host > 2013-11-07 14:43:15,835 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Deploy avoids pods: [], clusters: [], hosts: [1, 6] > 2013-11-07 14:43:15,836 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_9c110ba0@49591f8a > 2013-11-07 14:43:15,837 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:3, requested cpu: 500, requested ram: 536870912 > 2013-11-07 14:43:15,837 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Is ROOT volume READY (pool already allocated)?: Yes > 2013-11-07 14:43:15,837 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) This VM has last host_id specified, trying to choose the same host: 6 > 2013-11-07 14:43:15,838 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) The last host of this VM is in avoid set > 2013-11-07 14:43:15,838 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Cannot choose the last host to deploy this VM > 2013-11-07 14:43:15,853 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Cluster: 3 > 2013-11-07 14:43:15,918 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Checking resources in Cluster: 3 under Pod: 1 > 2013-11-07 14:43:15,921 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:3 > 2013-11-07 14:43:15,925 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-6-Routing]] > 2013-11-07 14:43:15,928 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-6-Routing]] > 2013-11-07 14:43:15,928 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512 > 2013-11-07 14:43:15,928 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host name: 10.223.59.66, hostId: 6 is in avoid set, skipping this and trying other available hosts > 2013-11-07 14:43:15,928 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts > 2013-11-07 14:43:15,928 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found > 2013-11-07 14:43:15,929 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found under this Cluster: 3 > 2013-11-07 14:43:15,931 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Could not find suitable Deployment Destination for this VM under any clusters, returning. > 2013-11-07 14:43:15,931 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Cluster: 3 > 2013-11-07 14:43:15,932 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) The specified cluster is in avoid set, returning. > 2013-11-07 14:43:15,942 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: 6 new host id: null host id before state transition: null > 2013-11-07 14:43:15,942 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Successfully transitioned to start state for VM[User|TestVM-1] reservation id = ad7d6cee-e20b-4945-8b02-3e2fb3aeeec8 > 2013-11-07 14:43:15,949 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Trying to deploy VM, vm has dcId: 1 and podId: 1 > 2013-11-07 14:43:15,949 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Deploy avoids pods: null, clusters: null, hosts: null > 2013-11-07 14:43:15,951 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Root volume is ready, need to place VM in volume's cluster > 2013-11-07 14:43:15,952 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Vol[11|vm=9|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 3 > 2013-11-07 14:43:15,954 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A1 for VM Id: 9 > 2013-11-07 14:43:15,957 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 1 to avoid set, since VM 11 is present on the host > 2013-11-07 14:43:15,958 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A2 for VM Id: 9 > 2013-11-07 14:43:15,960 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 6 to avoid set, since VM 12 is present on the host > 2013-11-07 14:43:15,965 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Deploy avoids pods: [], clusters: [], hosts: [1, 6] > 2013-11-07 14:43:15,966 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_9c110ba0@49591f8a > 2013-11-07 14:43:15,966 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:3, requested cpu: 500, requested ram: 536870912 > 2013-11-07 14:43:15,966 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Is ROOT volume READY (pool already allocated)?: Yes > 2013-11-07 14:43:15,966 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) This VM has last host_id specified, trying to choose the same host: 6 > 2013-11-07 14:43:15,967 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) The last host of this VM is in avoid set > 2013-11-07 14:43:15,967 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Cannot choose the last host to deploy this VM > 2013-11-07 14:43:15,967 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Cluster: 3 > 2013-11-07 14:43:15,990 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Checking resources in Cluster: 3 under Pod: 1 > 2013-11-07 14:43:15,990 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:3 > 2013-11-07 14:43:15,995 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-6-Routing]] > 2013-11-07 14:43:15,997 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-6-Routing]] > 2013-11-07 14:43:15,997 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512 > 2013-11-07 14:43:15,997 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host name: 10.223.59.66, hostId: 6 is in avoid set, skipping this and trying other available hosts > 2013-11-07 14:43:15,997 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts > 2013-11-07 14:43:15,997 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found > 2013-11-07 14:43:15,997 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found under this Cluster: 3 > 2013-11-07 14:43:15,998 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Could not find suitable Deployment Destination for this VM under any clusters, returning. > 2013-11-07 14:43:15,998 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Cluster: 3 > 2013-11-07 14:43:16,000 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) The specified cluster is in avoid set, returning. > 2013-11-07 14:43:16,003 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A1 for VM Id: 9 > 2013-11-07 14:43:16,005 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 1 to avoid set, since VM 11 is present on the host > 2013-11-07 14:43:16,005 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Processing affinity group A2 for VM Id: 9 > 2013-11-07 14:43:16,007 DEBUG [cloudstack.affinity.HostAntiAffinityProcessor] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Added host 6 to avoid set, since VM 12 is present on the host > 2013-11-07 14:43:16,013 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Deploy avoids pods: [], clusters: [3], hosts: [1, 6] > 2013-11-07 14:43:16,013 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_9c110ba0@49591f8a > 2013-11-07 14:43:16,013 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912 > 2013-11-07 14:43:16,014 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Is ROOT volume READY (pool already allocated)?: No > 2013-11-07 14:43:16,014 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) This VM has last host_id specified, trying to choose the same host: 6 > 2013-11-07 14:43:16,015 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) The last host of this VM is in avoid set > 2013-11-07 14:43:16,015 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Cannot choose the last host to deploy this VM > 2013-11-07 14:43:16,015 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Pod: 1 > 2013-11-07 14:43:16,018 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1 > 2013-11-07 14:43:16,037 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Removing from the clusterId list these clusters from avoid set: [3] > 2013-11-07 14:43:16,078 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Checking resources in Cluster: 1 under Pod: 1 > 2013-11-07 14:43:16,078 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1 > 2013-11-07 14:43:16,082 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]] > 2013-11-07 14:43:16,084 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]] > 2013-11-07 14:43:16,084 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512 > 2013-11-07 14:43:16,084 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host name: 10.223.59.67, hostId: 1 is in avoid set, skipping this and trying other available hosts > 2013-11-07 14:43:16,084 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts > 2013-11-07 14:43:16,084 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found > 2013-11-07 14:43:16,084 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No suitable hosts found under this Cluster: 1 > 2013-11-07 14:43:16,085 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Could not find suitable Deployment Destination for this VM under any clusters, returning. > 2013-11-07 14:43:16,086 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Searching resources only under specified Pod: 1 > 2013-11-07 14:43:16,086 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1 > 2013-11-07 14:43:16,088 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Removing from the clusterId list these clusters from avoid set: [1, 3] > 2013-11-07 14:43:16,089 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) No clusters found after removing disabled clusters and clusters in avoid list, returning. > 2013-11-07 14:43:16,218 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: 6 new host id: null host id before state transition: null > 2013-11-07 14:43:16,260 INFO [user.vm.StartVMCmd] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|TestVM-1]Scope=interface com.cloud.dc.DataCenter; id=1 > 2013-11-07 14:43:16,260 INFO [user.vm.StartVMCmd] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Unable to create a deployment for VM[User|TestVM-1], Please check the affinity groups provided, there may not be sufficient capacity to follow them > com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|TestVM-1]Scope=interface com.cloud.dc.DataCenter; id=1 > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:841) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577) > at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:242) > at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3440) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1959) > at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-11-07 14:43:16,263 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-31:job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ]) Complete async job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ], jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|TestVM-1], Please check the affinity groups provided, there may not be sufficient capacity to follow them > 2013-11-07 14:43:17,129 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 8-1258: Processing Seq 8-1258: { Cmd , MgmtId: -1, via: 8, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":6,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] } > 2013-11-07 14:43:17,137 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 8-1258: Sending Seq 8-1258: { Ans: , MgmtId: 7471666038533, via: 8, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-11-07 14:43:18,900 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START=== 10.214.4.75 -- GET command=queryAsyncJobResult&jobId=c6b67100-24d5-4eaf-8104-a93c3c75ce16&response=json&sessionkey=Xj52fOTZWqAUf0nnCSUZlybSVfI%3D&_=1383864704475 > 2013-11-07 14:43:18,913 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-2:null) Async job-40 = [ c6b67100-24d5-4eaf-8104-a93c3c75ce16 ] completed > 2013-11-07 14:43:18,918 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END=== 10.214.4.75 -- GET command=queryAsyncJobResult&jobId=c6b67100-24d5-4eaf-8104-a93c3c75ce16&response=json&sessionkey=Xj52fOTZWqAUf0nnCSUZlybSVfI%3D&_=1383864704475 -- This message was sent by Atlassian JIRA (v6.1#6144)