Login
Register
Telephone Support
Select a product
All,
I have finally successfully configured Cloud Platform trial version and ready to create VM to build a test offering however when I try to create a VM as root or as a user I'm getting the following message: Unable to create a deployment for VM
Please see below some log messages from the Management Server. I need some help please
2013-12-27 18:26:30,534 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START=== 192.168.168.250 -- GET command=listNetworks&trafficType=Guest&zoneId=00fac1a6-c3a5-4c53-a3ff-d9930e0c46bf&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186780711
2013-12-27 18:26:30,559 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END=== 192.168.168.250 -- GET command=listNetworks&trafficType=Guest&zoneId=00fac1a6-c3a5-4c53-a3ff-d9930e0c46bf&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186780711
2013-12-27 18:26:30,741 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===START=== 192.168.168.250 -- GET command=listSecurityGroups&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&domainid=11f9580c-b37e-4718-acd9-d065505cdcbb&account=cwilliams391&_=1388186780915
2013-12-27 18:26:30,760 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-24:null) Access granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] to Domain:3/Net-IT/ by AffinityGroupAccessChecker_EnhancerByCloudStack_6bdbded2
2013-12-27 18:26:30,762 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-24:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:30,767 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===END=== 192.168.168.250 -- GET command=listSecurityGroups&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&domainid=11f9580c-b37e-4718-acd9-d065505cdcbb&account=cwilliams391&_=1388186780915
2013-12-27 18:26:34,579 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 3-2098: Processing Seq 3-2098: { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2013-12-27 18:26:34,641 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 3-2098: Sending Seq 3-2098: { Ans: , MgmtId: 132129486677709, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-27 18:26:38,841 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2013-12-27 18:26:39,240 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2013-12-27 18:26:39,580 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 3-2099: Processing Seq 3-2099: { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2013-12-27 18:26:39,702 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-12-27 18:26:39,704 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-12-27 18:26:39,707 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 3-2099: Sending Seq 3-2099: { Ans: , MgmtId: 132129486677709, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-27 18:26:39,733 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-12-27 18:26:39,734 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-12-27 18:26:43,105 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START=== 192.168.168.250 -- GET command=deployVirtualMachine&zoneId=00fac1a6-c3a5-4c53-a3ff-d9930e0c46bf&templateId=6915198c-6f19-11e3-96c8-8a8910b55ba7&hypervisor=XenServer&serviceOfferingId=127bbf46-af57-4de9-a08f-b6411e5a4697&diskOfferingId=557e5531-d5ff-400e-b699-d8a356899e1b&securitygroupids=909108f0-3735-4cb4-bed5-09414f20096c&displayname=carl&name=carl&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186793283
2013-12-27 18:26:43,114 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-11:null) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2013-12-27 18:26:43,118 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-11:null) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2013-12-27 18:26:43,121 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-11:null) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2013-12-27 18:26:43,123 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-11:null) ControlledEntity name is:com.cloud.network.security.SecurityGroup
2013-12-27 18:26:43,125 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,127 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,128 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to com.cloud.network.security.SecurityGroupVO$$EnhancerByCGLIB$$6edf5bbc@43e651d3 granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,131 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Tmpl[5-VHD-centos56-x86_64-xen granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,132 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,138 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,164 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,164 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-11:null) Access to com.cloud.network.security.SecurityGroupVO$$EnhancerByCGLIB$$6edf5bbc@42dfab8e granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,306 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-11:null) Allocating in the DB for vm
2013-12-27 18:26:43,323 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-11:null) Allocating entries for VM: VM[User|carl]
2013-12-27 18:26:43,324 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-11:null) Allocating nics for VM[User|carl]
2013-12-27 18:26:43,324 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-11:null) Allocating nic for vm VM[User|carl] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2013-12-27 18:26:43,333 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-11:null) Allocating disks for VM[User|carl]
2013-12-27 18:26:43,352 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-11:null) Allocation completed for VM: VM[User|carl]
2013-12-27 18:26:43,352 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-11:null) Successfully allocated DB entry for VM[User|carl]
2013-12-27 18:26:43,724 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-11:null) submit async job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ], details: AsyncJobVO {id:35, userId: 7, accountId: 7, sessionKey: null, instanceType: VirtualMachine, instanceId: 16, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"AelDWfiHsmTfwtNjtk5BRrkv5As\u003d","cmdEventType":"VM.CREATE","ctxUserId":"7","serviceOfferingId":"127bbf46-af57-4de9-a08f-b6411e5a4697","httpmethod":"GET","securitygroupids":"909108f0-3735-4cb4-bed5-09414f20096c","zoneId":"00fac1a6-c3a5-4c53-a3ff-d9930e0c46bf","id":"16","templateId":"6915198c-6f19-11e3-96c8-8a8910b55ba7","response":"json","hypervisor":"XenServer","name":"carl","diskOfferingId":"557e5531-d5ff-400e-b699-d8a356899e1b","_":"1388186793283","ctxAccountId":"7","ctxStartEventId":"164","displayname":"carl"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 132129486677709, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-12-27 18:26:43,725 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]
2013-12-27 18:26:43,727 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END=== 192.168.168.250 -- GET command=deployVirtualMachine&zoneId=00fac1a6-c3a5-4c53-a3ff-d9930e0c46bf&templateId=6915198c-6f19-11e3-96c8-8a8910b55ba7&hypervisor=XenServer&serviceOfferingId=127bbf46-af57-4de9-a08f-b6411e5a4697&diskOfferingId=557e5531-d5ff-400e-b699-d8a356899e1b&securitygroupids=909108f0-3735-4cb4-bed5-09414f20096c&displayname=carl&name=carl&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186793283
2013-12-27 18:26:43,730 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2013-12-27 18:26:43,732 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2013-12-27 18:26:43,734 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2013-12-27 18:26:43,736 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ControlledEntity name is:com.cloud.network.security.SecurityGroup
2013-12-27 18:26:43,738 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,740 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Access to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,741 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Access to com.cloud.network.security.SecurityGroupVO$$EnhancerByCGLIB$$6edf5bbc@59f4de28 granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,743 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Access to Tmpl[5-VHD-centos56-x86_64-xen granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,805 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Access to VM[User|carl] granted to Acct[0dc1060b-a112-46d8-816f-d963b0435abc-cwilliams391] by DomainChecker_EnhancerByCloudStack_851647cd
2013-12-27 18:26:43,846 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: [], clusters: [], hosts: [2]
2013-12-27 18:26:43,847 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_7c41c31e@5c1130f8
2013-12-27 18:26:43,847 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2013-12-27 18:26:43,847 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Is ROOT volume READY (pool already allocated)?: No
2013-12-27 18:26:43,847 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Searching all possible resources under this Zone: 1
2013-12-27 18:26:43,848 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2013-12-27 18:26:43,850 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Removing from the clusterId list these clusters from avoid set: []
2013-12-27 18:26:43,855 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking resources in Cluster: 1 under Pod: 1
2013-12-27 18:26:43,856 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-12-27 18:26:43,859 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-2-Routing], Host[-1-Routing]]
2013-12-27 18:26:43,861 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-2-Routing], Host[-1-Routing]]
2013-12-27 18:26:43,861 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
2013-12-27 18:26:43,861 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Host name: xenserver-PHL1, hostId: 2 is in avoid set, skipping this and trying other available hosts
2013-12-27 18:26:43,865 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Hosts's actual total CPU: 44800 and CPU after applying overprovisioning: 44800
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Free CPU: 44300 , Requested CPU: 1000
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Free RAM: 130644566016 , Requested RAM: 1073741824
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total: 44800, total with overprovisioning: 44800; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-12-27 18:26:43,866 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 268435456, reserved: 0, total: 130913001472; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-12-27 18:26:43,866 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2013-12-27 18:26:43,866 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2013-12-27 18:26:43,868 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking suitable pools for volume (Id, Type): (26,ROOT)
2013-12-27 18:26:43,868 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) We need to allocate new storagepool for this volume
2013-12-27 18:26:43,868 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Calling StoragePoolAllocators to find suitable pools
2013-12-27 18:26:43,869 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-12-27 18:26:43,869 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-12-27 18:26:43,869 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Looking for pools in dc: 1 pod:1 cluster:1
2013-12-27 18:26:43,872 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if storage pool is suitable, name: null ,poolId: 3
2013-12-27 18:26:43,874 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:43,883 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[26|vm=16|ROOT]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:43,883 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2013-12-27 18:26:43,883 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking suitable pools for volume (Id, Type): (27,DATADISK)
2013-12-27 18:26:43,883 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) We need to allocate new storagepool for this volume
2013-12-27 18:26:43,884 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Calling StoragePoolAllocators to find suitable pools
2013-12-27 18:26:43,884 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-12-27 18:26:43,884 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-12-27 18:26:43,884 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Looking for pools in dc: 1 pod:1 cluster:1
2013-12-27 18:26:43,886 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if storage pool is suitable, name: null ,poolId: 3
2013-12-27 18:26:43,889 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:43,894 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[27|vm=16|DATADISK]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:43,895 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2013-12-27 18:26:43,895 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2013-12-27 18:26:43,895 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if host: 1 can access any suitable storage pool for volume: ROOT
2013-12-27 18:26:43,895 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Host: 1 can access pool: 3
2013-12-27 18:26:43,897 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:43,905 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[26|vm=16|ROOT]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:43,905 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if host: 1 can access any suitable storage pool for volume: DATADISK
2013-12-27 18:26:43,906 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Host: 1 can access pool: 3
2013-12-27 18:26:43,907 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:43,913 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[27|vm=16|DATADISK]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:43,913 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Found a potential host id: 1 name: xenserver-PHL2 and associated storage pools for this VM
2013-12-27 18:26:43,914 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(27|DATADISK-->Pool(3), Volume(26|ROOT-->Pool(3))]
2013-12-27 18:26:43,981 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2013-12-27 18:26:43,981 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Successfully transitioned to start state for VM[User|carl] reservation id = c156fe25-8658-4782-a3b9-4d9138b80414
2013-12-27 18:26:44,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-12-27 18:26:44,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) advanceStart: DeploymentPlan is provided, using dcId:1, podId: 1, clusterId: 1, hostId: 1, poolId: null
2013-12-27 18:26:44,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: null, clusters: null, hosts: null
2013-12-27 18:26:44,042 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: [], clusters: [], hosts: [2]
2013-12-27 18:26:44,042 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_7c41c31e@5c1130f8
2013-12-27 18:26:44,042 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram: 1073741824
2013-12-27 18:26:44,042 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Is ROOT volume READY (pool already allocated)?: No
2013-12-27 18:26:44,042 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 1
2013-12-27 18:26:44,043 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2013-12-27 18:26:44,044 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking suitable pools for volume (Id, Type): (26,ROOT)
2013-12-27 18:26:44,044 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) We need to allocate new storagepool for this volume
2013-12-27 18:26:44,045 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Calling StoragePoolAllocators to find suitable pools
2013-12-27 18:26:44,046 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-12-27 18:26:44,046 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-12-27 18:26:44,046 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Looking for pools in dc: 1 pod:1 cluster:1
2013-12-27 18:26:44,049 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if storage pool is suitable, name: null ,poolId: 3
2013-12-27 18:26:44,051 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:44,060 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[26|vm=16|ROOT]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:44,060 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2013-12-27 18:26:44,060 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking suitable pools for volume (Id, Type): (27,DATADISK)
2013-12-27 18:26:44,060 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) We need to allocate new storagepool for this volume
2013-12-27 18:26:44,060 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Calling StoragePoolAllocators to find suitable pools
2013-12-27 18:26:44,060 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-12-27 18:26:44,060 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-12-27 18:26:44,060 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Looking for pools in dc: 1 pod:1 cluster:1
2013-12-27 18:26:44,063 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if storage pool is suitable, name: null ,poolId: 3
2013-12-27 18:26:44,065 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:44,071 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[27|vm=16|DATADISK]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:44,071 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2013-12-27 18:26:44,071 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2013-12-27 18:26:44,071 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if host: 1 can access any suitable storage pool for volume: ROOT
2013-12-27 18:26:44,072 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Host: 1 can access pool: 3
2013-12-27 18:26:44,073 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:44,082 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[26|vm=16|ROOT]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:44,082 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking if host: 1 can access any suitable storage pool for volume: DATADISK
2013-12-27 18:26:44,082 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Host: 1 can access pool: 3
2013-12-27 18:26:44,083 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool 3 for storage, totalSize: 48769794048, usedBytes: 6404702208, usedPct: 0.13132518463572743, disable threshold: 0.85
2013-12-27 18:26:44,089 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Checking pool: 3 for volume allocation [Vol[27|vm=16|DATADISK]], maxSize : 97539588096, totalAllocatedSize : 4194304000, askingSize : 21474836480, allocated disable threshold: 0.85
2013-12-27 18:26:44,090 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Found a potential host id: 1 name: xenserver-PHL2 and associated storage pools for this VM
2013-12-27 18:26:44,090 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) StorageCollector is running...
2013-12-27 18:26:44,090 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(27|DATADISK-->Pool(3), Volume(26|ROOT-->Pool(3))]
2013-12-27 18:26:44,090 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deployment found - P0=VM[User|carl], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(27|DATADISK-->Pool(3), Volume(26|ROOT-->Pool(3))]
2013-12-27 18:26:44,154 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 4-1417543939: Received: { Ans: , MgmtId: 132129486677709, via: 4, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2013-12-27 18:26:44,160 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 1-327090720: Executing request
2013-12-27 18:26:44,165 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 1 host id before state transition: null
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Hosts's actual total CPU: 44800 and CPU after applying overprovisioning: 44800
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) We are allocating VM, increasing the used capacity of this host:1
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Current Used CPU: 500 , Free CPU:44300 ,Requested CPU: 1000
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Current Used RAM: 268435456 , Free RAM:130644566016 ,Requested RAM: 1073741824
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) CPU STATS after allocation: for host: 1, old used: 500, old reserved: 0, actual total: 44800, total with overprovisioning: 44800; new used:1500, reserved:0; requested cpu:1000,alloc_from_last:false
2013-12-27 18:26:44,174 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) RAM STATS after allocation: for host: 1, old used: 268435456, old reserved: 0, total: 130913001472; new used: 1342177280, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2013-12-27 18:26:44,266 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM is being created in podId: 1
2013-12-27 18:26:44,274 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Network id=204 is already implemented
2013-12-27 18:26:44,344 DEBUG [db.Transaction.Transaction] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Rolling back the transaction: Time = 7 Name = -AsyncJobManagerImpl$1.run:494-Executors$RunnableAdapter.call:471-FutureTask.run:262-ThreadPoolExecutor.runWorker:1145-ThreadPoolExecutor$Worker.run:615-Thread.run:744; called by -Transaction.rollback:897-Transaction.removeUpTo:840-Transaction.close:664-TransactionContextBuilder.interceptException:63-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:133-NetworkManagerImpl.assignPublicIpAddress:376-DirectPodBasedNetworkGuru.getIp:186-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-DirectPodBasedNetworkGuru.reserve:153-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-NetworkManagerImpl.prepareNic:2166-NetworkManagerImpl.prepare:2136
2013-12-27 18:26:44,344 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Insufficient capacity
com.cloud.exception.InsufficientAddressCapacityException: Insufficient address capacityScope=interface com.cloud.dc.Pod; id=1
at com.cloud.network.NetworkManagerImpl.fetchNewPublicIp(NetworkManagerImpl.java:472)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at com.cloud.network.NetworkManagerImpl.assignPublicIpAddress(NetworkManagerImpl.java:376)
at com.cloud.network.guru.DirectPodBasedNetworkGuru.getIp(DirectPodBasedNetworkGuru.java:186)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at com.cloud.network.guru.DirectPodBasedNetworkGuru.reserve(DirectPodBasedNetworkGuru.java:153)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2166)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2136)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3442)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3002)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2988)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
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.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2013-12-27 18:26:44,401 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Cleaning up resources for the vm VM[User|carl] in Starting state
2013-12-27 18:26:44,403 DEBUG [agent.transport.Request] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Seq 1-327090721: Sending { Cmd , MgmtId: 132129486677709, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-7-16-VM","wait":0}}] }
2013-12-27 18:26:44,403 DEBUG [agent.transport.Request] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Seq 1-327090721: Executing: { Cmd , MgmtId: 132129486677709, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-7-16-VM","wait":0}}] }
2013-12-27 18:26:44,403 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-185:null) Seq 1-327090721: Executing request
2013-12-27 18:26:44,422 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 1-327090720: Response Received:
2013-12-27 18:26:44,422 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-327090720: Received: { Ans: , MgmtId: 132129486677709, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2013-12-27 18:26:44,484 INFO [xen.resource.CitrixResourceBase] (DirectAgent-185:null) VM does not exist on XenServerabf38ca8-e00f-40e6-89da-0e4794ee75b9
2013-12-27 18:26:44,484 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-185:null) Seq 1-327090721: Response Received:
2013-12-27 18:26:44,484 DEBUG [agent.transport.Request] (DirectAgent-185:null) Seq 1-327090721: Processing: { Ans: , MgmtId: 132129486677709, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2013-12-27 18:26:44,484 DEBUG [agent.manager.AgentAttache] (DirectAgent-185:null) Seq 1-327090721: No more commands found
2013-12-27 18:26:44,484 DEBUG [agent.transport.Request] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Seq 1-327090721: Received: { Ans: , MgmtId: 132129486677709, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-12-27 18:26:44,548 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Asking VirtualRouter to release Nic[21-16-c156fe25-8658-4782-a3b9-4d9138b80414-null]
2013-12-27 18:26:44,551 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Asking SecurityGroupProvider to release Nic[21-16-c156fe25-8658-4782-a3b9-4d9138b80414-null]
2013-12-27 18:26:44,551 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Successfully released network resources for the vm VM[User|carl]
2013-12-27 18:26:44,551 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Successfully cleanued up resources for the vm VM[User|carl] in Starting state
2013-12-27 18:26:44,558 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: [1], clusters: [], hosts: [1, 2]
2013-12-27 18:26:44,558 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_7c41c31e@5c1130f8
2013-12-27 18:26:44,558 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram: 1073741824
2013-12-27 18:26:44,558 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Is ROOT volume READY (pool already allocated)?: No
2013-12-27 18:26:44,558 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 1
2013-12-27 18:26:44,560 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) The specified host is in avoid set
2013-12-27 18:26:44,560 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Cannnot deploy to specified host, returning.
2013-12-27 18:26:44,658 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1
2013-12-27 18:26:44,666 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Hosts's actual total CPU: 44800 and CPU after applying overprovisioning: 44800
2013-12-27 18:26:44,666 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Hosts's actual total RAM: 130913004096 and RAM after applying overprovisioning: 130913001472
2013-12-27 18:26:44,666 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) release cpu from host: 1, old used: 1500,reserved: 0, actual total: 44800, total with overprovisioning: 44800; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-27 18:26:44,666 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) release mem from host: 1, old used: 1342177280,reserved: 0, total: 130913001472; new used: 268435456,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-27 18:26:44,891 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2013-12-27 18:26:44,891 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Successfully transitioned to start state for VM[User|carl] reservation id = a8378d70-f35e-47f2-94e8-fcbf1c963565
2013-12-27 18:26:44,941 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to deploy VM, vm has dcId: 1 and podId: 1
2013-12-27 18:26:44,941 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: [1], clusters: [], hosts: [1, 2]
2013-12-27 18:26:44,949 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Deploy avoids pods: [1], clusters: [], hosts: [1, 2]
2013-12-27 18:26:44,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_7c41c31e@5c1130f8
2013-12-27 18:26:44,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 1000, requested ram: 1073741824
2013-12-27 18:26:44,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Is ROOT volume READY (pool already allocated)?: No
2013-12-27 18:26:44,950 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Searching resources only under specified Pod: 1
2013-12-27 18:26:44,950 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) The specified pod is in avoid set, returning.
2013-12-27 18:26:45,035 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2013-12-27 18:26:45,081 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Destroying vm VM[User|carl] as it failed to create on Host with Id:null
2013-12-27 18:26:45,235 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) 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-27 18:26:45,442 WARN [apache.cloudstack.alerts] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 16, on Host with Id: null
2013-12-27 18:26:45,726 INFO [user.vm.DeployVMCmd] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|carl]Scope=interface com.cloud.dc.DataCenter; id=1
2013-12-27 18:26:45,727 INFO [user.vm.DeployVMCmd] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Unable to create a deployment for VM[User|carl]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|carl]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:237)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3442)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3002)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2988)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
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.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2013-12-27 18:26:45,729 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Complete async job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ], jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|carl]
2013-12-27 18:26:46,532 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null) Ping from 4
2013-12-27 18:26:46,915 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START=== 192.168.168.250 -- GET command=queryAsyncJobResult&jobId=e1ebce9d-18d7-4cf0-98de-22399a6ec49e&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186797093
2013-12-27 18:26:46,928 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-22:null) Async job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ] completed
2013-12-27 18:26:46,932 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END=== 192.168.168.250 -- GET command=queryAsyncJobResult&jobId=e1ebce9d-18d7-4cf0-98de-22399a6ec49e&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186797093
2013-12-27 18:26:47,047 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START=== 192.168.168.250 -- GET command=listVirtualMachines&id=0ad3abc4-b171-4fe3-81e2-f069a365a900&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186797186
2013-12-27 18:26:47,076 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END=== 192.168.168.250 -- GET command=listVirtualMachines&id=0ad3abc4-b171-4fe3-81e2-f069a365a900&response=json&sessionkey=AelDWfiHsmTfwtNjtk5BRrkv5As%3D&_=1388186797186
2013-12-27 18:26:49,580 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 3-2100: Processing Seq 3-2100: { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2013-12-27 18:26:49,617 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 3-2100: Sending Seq 3-2100: { Ans: , MgmtId: 132129486677709, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
17 comments
0
Does anyone have any idea why I'm unable to create a VM Deployment in CloudPlatform?
0
How much memory do you have (run free -m) and also disk space (df -h).
The interesting error message is:
2013-12-27 18:26:45,727 INFO [user.vm.DeployVMCmd] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) Unable to create a deployment for VM[User|carl]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|carl]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:237)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3442)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3002)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2988)
at
0
Also, what is the hostname as this error is striking:
2013-12-27 18:26:45,442 WARN [apache.cloudstack.alerts] (Job-Executor-35:job-35 = [ e1ebce9d-18d7-4cf0-98de-22399a6ec49e ]) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 16, on Host with Id: null
0
Hello Carl,
I was just look thoug your log, you have an insuffienf server capacity message
So which kind of vm are you trying to create, a windows server - have you enabled the virtualization on the CPU on the HOST, you are using with cloud stack.
Have you checked how many vm/volumes/memory the user can use -1 is all you want.. 
Kind regards
Gert
0
All,
I have a few things to investigate here but before I begin I need to know some information as where to look because I'm new to Linux and Citrix. Can I get some information on where to look for "How much memory do you have (run free -m) and also disk space (df -h)
" for the following information?
Management server is running on a separate physical server
NFS server is running on a VM on Xensever
Also were using "vm/volumes/memory the user can use -1" on all accounts.
Carl
0
Jesse
This is the much memory I have on the management server - is this where I should be looking?
free -m
total used free shared buffers cached
Mem: 3881 3861 20 0 148 3479
-/+ buffers/cache: 233 3648
Swap: 6063 0 6063
0
Um... yes.
You have 20 Megabytes of memory free for the virtualization layer:
free -m
total used free shared buffers cached
Mem: 3881 3861 20 0 148 3479
-/+ buffers/cache: 233 3648
Swap: 6063 0 6063
Can you provide the output of /boot/extlinux.conf? Also -- the command, top -n1
This is why you can't get the VM created... there is not enough memory... yikes!
0
Thanks for the information Jesse!
So is this information is on the vitalization sever and is this where I need to run the command /boot/extlinux.conf?
0
NFS Sever:
/dev/mapper/VolGroup-lv_root
47G 722M 44G 2% /
tmpfs 1.9G 0 1.9G 0% /dev/shm
/dev/xvda1 485M 31M 429M 7% /boot
/dev/mapper/VolGroup-lv_home
46G 6.1G 38G 15% /home
Management Server:
[root@MngtServer ~]# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/vg_mngtserver-lv_root 50G 15G 32G 32% /
tmpfs 1.9G 0 1.9G 0% /dev/shm
/dev/sda1 485M 39M 421M 9% /boot
/dev/mapper/vg_mngtserver-lv_home 7.2T 179M 6.8T 1% /home
0
Jesse,
which sever shall I look to see the low disk lever. Also, I'm unable to find this file "/boot/extlinux.conf" ( on my MangSever.)
"Can you provide the output of /boot/extlinux.conf? Also -- the command, top -n1
This is why you can't get the VM created... there is not enough memory... yikes!"
Carl
0
0
Jesse,
Please see the output you requested from the Mngt. Server:
[root@MngtServer ~]# top -n1
top - 13:15:14 up 1 day, 5:05, 2 users, load average: 0.01, 0.10, 0.17
Tasks: 178 total, 1 running, 177 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.2%us, 0.1%sy, 0.0%ni, 97.3%id, 2.5%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 3911436k total, 2063948k used, 1847488k free, 158752k buffers
Swap: 4046840k total, 0k used, 4046840k free, 704976k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
17463 root 20 0 15032 1176 836 R 1.8 0.0 0:00.06 top
1 root 20 0 19364 1536 1228 S 0.0 0.0 0:00.94 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
4 root 20 0 0 0 0 S 0.0 0.0 0:00.46 ksoftirqd/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
6 root RT 0 0 0 0 S 0.0 0.0 0:00.11 watchdog/0
7 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/1
8 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/1
9 root 20 0 0 0 0 S 0.0 0.0 0:00.54 ksoftirqd/1
10 root RT 0 0 0 0 S 0.0 0.0 0:00.10 watchdog/1
11 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/2
12 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/2
13 root 20 0 0 0 0 S 0.0 0.0 0:00.38 ksoftirqd/2
14 root RT 0 0 0 0 S 0.0 0.0 0:00.10 watchdog/2
15 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/3
16 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/3
[root@MngtServer ~]#
[root@NFSServer ~]# top -n1
top - 13:17:53 up 3 days, 2:41, 1 user, load average: 0.00, 0.00, 0.00
Tasks: 86 total, 1 running, 85 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.0%us, 0.1%sy, 0.0%ni, 99.5%id, 0.4%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 3974984k total, 3954504k used, 20480k free, 186412k buffers
Swap: 6209528k total, 0k used, 6209528k free, 3528384k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1 root 20 0 19272 1516 1252 S 0.0 0.0 0:00.32 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
4 root 20 0 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
6 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
7 root 20 0 0 0 0 S 0.0 0.0 0:00.03 events/0
8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuset
9 root 20 0 0 0 0 S 0.0 0.0 0:00.00 khelper
10 root 20 0 0 0 0 S 0.0 0.0 0:00.00 netns
11 root 20 0 0 0 0 S 0.0 0.0 0:00.00 async/mgr
12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 pm
13 root 20 0 0 0 0 S 0.0 0.0 0:00.00 xenwatch
14 root 20 0 0 0 0 S 0.0 0.0 0:00.28 xenbus
15 root 20 0 0 0 0 S 0.0 0.0 0:00.00 sync_supers
16 root 20 0 0 0 0 S 0.0 0.0 0:00.00 bdi-default
17 root 20 0 0 0 0 S 0
Anyone who can provide some insight is appreciated. Need to figure out if I should use this platform or something else.
0
Hey, Carl --
What I was interested in was the kernel configuration for DOM0 in /boot/extlinux.conf -- if you can execute (and paste) it would be greatly appreciated:
cat /boot/extlinux.conf
--jkbs
This is why you can't get the VM created... there is not enough memory... yikes!"
Do I need to check the memory on the Mngt. Server or on my host server?
0
All thx for your help I was able to create the VM(s) by starting from scratch and allocate my SAN as primary storage. I'm not unable to add ISO files in CloudPlatform. Once I register the ISO and check the status this is what I receive:
Ready No Status Connection refused
Apache is configure and working on the Management server. My server IP is 192.168.168.193.. can someone send me a sample config?
Carl
0
Good evening, Carl --
Just to seek clarification:
1. You can complete the ISO Storage setup (no errors), right?
2. Can you then see the ISO Storage and its contents?
I am curious if you have enable internal uploads enabled in CloudStack. More importantly, I am wondering if there is not a network issue? The following link discusses storage setup on page 18 and on-ward -- specifically for IPTABLES, etc. The second article is related to troubleshooting ISO/Template/Secondary Storage issues:
Keep us posted!
--jkbs
0
I have the same kind of problem with new instances.
I have cloudstack, installed on xen-server 6.5. Current System Capacity is:
Zone: test 27% Management IP Addresses 3 / 11
Zone: test 10% CPU 1.00 GHz / 9.31 GHz
Zone: test 10% Memory 1.50 GB / 14.66 GB
Zone: test 8% Secondary Storage 4.09 GB / 49.09 GB
Zone: test 7% Primary Storage 7.14 GB / 98.18 GB
Zone: test 1% Shared Network IPs 2 / 101
Zone: test % GPU /
But when i'm trying to create new instance with ISO (centos 7, debian 8, ubuntu 14 - any of those) - i'm getting next error stacktrace in logs:
2015-07-13 14:26:41,411 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin] (API-Job-Executor-20:ctx-ecf1cc36 job-61 ctx-79c82656) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|i-2-10-VM]Scope=interface com.cloud.dc.DataCenter; id=1
2015-07-13 14:26:41,412 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin] (API-Job-Executor-20:ctx-ecf1cc36 job-61 ctx-79c82656) Unable to create a deployment for VM[User|i-2-10-VM]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|i-2-10-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:214)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:200)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3583)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3227)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3215)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy213.startVirtualMachine(Unknown Source)
at org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:50)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
0
Insufficient Server Capacity could mean anything (CPU/RAM) - you should trace back job-61 to locate the exact resource mgmt server is complaining about; there are log messages that clearly state which resource is the problem along with the actual figures.
0
Ask, Discuss, Answer
