William, There can be several seasons. Could you attach the agent.log?
-Wei 2013/6/19 William Jiang <william.ji...@manwin.com> > Anybody has the same situation before ? Any comments or suggestions will > be great appreciated. > > Thanks, > William > > > -----Original Message----- > From: William Jiang [mailto:william.ji...@manwin.com] > Sent: June-18-13 12:45 PM > To: dev@cloudstack.apache.org; us...@cloudstack.apache.org > Subject: RE: starting VM and get error of "unable to create a deployment > for VM[user|i-2-107-VM]" > > Hi, > Ubuntu 12.04 does not fully supported by xenserver 6.0.2, but we have some > Ubuntu 12.04 work well, and we also saw same issue in one windows server > 2008 R2 VM which is fully supported by hypervisor. > > The complete logs as following: > > > ######################################################################################################################################################### > 2013-06-14 12:28:34,328 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-18:null) submit async job-626, details: AsyncJobVO {id:626, > userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, > instanceId: 107, cmd: com.cloud.api.commands.StartVMCmd, cmdOriginator: > null, cmdInfo: > {"id":"2d7d30a0-83d1-4050-a8dd-1b702fbb08e6","response":"json","sessionkey":"eihe8Buev1Ale+nhxw+w1nqQ\u003d","ctxUserId":"2","_":"1371227586576","ctxAccountId":"2","ctxStartEventId":"2584"}, > cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, > processStatus: 0, resultCode: 0, result: null, initMsid: 110492071566, > completeMsid: null, lastUpdated: null, lastPolled: null, created: null} > 2013-06-14 12:28:34,331 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-16:job-626) Executing com.cloud.api.commands.StartVMCmd for > job-626 > 2013-06-14 12:28:34,349 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Service SecurityGroup is not supported in the > network id=214 > 2013-06-14 12:28:34,353 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Service SecurityGroup is not supported in the > network id=214 > 2013-06-14 12:28:34,355 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) VM state transitted from :Stopped to Starting > with event: StartRequestedvm's original host id: 9 new host id: null host > id before state transition: null > 2013-06-14 12:28:34,356 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Successfully transitioned to start state for > VM[User|i-2-107-VM] reservation id = 3ee7e4d1-a732-4e6b-96d3-eb02caec4df3 > 2013-06-14 12:28:34,357 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Trying to deploy VM, vm has dcId: 3 and podId: 3 > 2013-06-14 12:28:34,357 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Deploy avoids pods: null, clusters: null, hosts: > null > 2013-06-14 12:28:34,359 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Root volume is ready, need to place VM in > volume's cluster > 2013-06-14 12:28:34,359 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Vol[129|vm=107|ROOT] is READY, changing > deployment plan to use this pool's dcId: 3 , podId: 3 , and clusterId: 3 > 2013-06-14 12:28:34,360 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) DeploymentPlanner allocation algorithm: random > 2013-06-14 12:28:34,360 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Trying to allocate a host and storage pools from > dc:3, pod:3,cluster:3, requested cpu: 1000, requested ram: 1073741824 > 2013-06-14 12:28:34,360 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Is ROOT volume READY (pool already allocated)?: > Yes > 2013-06-14 12:28:34,360 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) This VM has last host_id specified, trying to > choose the same host: 9 > 2013-06-14 12:28:34,361 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Checking if host: 9 has enough capacity for > requested CPU: 1000 and requested RAM: 1073741824 , > cpuOverprovisioningFactor: 1.0 > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Hosts's actual total CPU: 18616 and CPU after > applying overprovisioning: 18616 > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) We need to allocate to the last host again, so > checking if there is enough reserved capacity > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Reserved CPU: 0 , Requested CPU: 1000 > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Reserved RAM: 0 , Requested RAM: 1073741824 > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) STATS: Failed to alloc resource from host: 9 > reservedCpu: 0, requested cpu: 1000, reservedMem: 0, requested mem: > 1073741824 > 2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Host does not have enough reserved CPU available, > cannot allocate to this host. > 2013-06-14 12:28:34,362 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) The last host of this VM does not have enough > capacity > 2013-06-14 12:28:34,362 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Cannot choose the last host to deploy this VM > 2013-06-14 12:28:34,362 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Searching resources only under specified Cluster: > 3 > 2013-06-14 12:28:34,366 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Checking resources in Cluster: 3 under Pod: 3 > 2013-06-14 12:28:34,366 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Calling HostAllocators to find suitable hosts > 2013-06-14 12:28:34,366 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Looking for hosts in dc: > 3 pod:3 cluster:3 > 2013-06-14 12:28:34,367 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) FirstFitAllocator has 1 > hosts to check for allocation: [Host[-9-Routing]] > 2013-06-14 12:28:34,368 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Found 1 hosts for > allocation after prioritization: [Host[-9-Routing]] > 2013-06-14 12:28:34,368 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Looking for > speed=1000Mhz, Ram=1024 > 2013-06-14 12:28:34,369 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Checking if host: 9 has > enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , > cpuOverprovisioningFactor: 1.0 > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Hosts's actual total > CPU: 18616 and CPU after applying overprovisioning: 18616 > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Free CPU: 5116 , > Requested CPU: 1000 > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Free RAM: 27069551616 , > Requested RAM: 1073741824 > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Host has enough CPU and > RAM available > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) STATS: Can alloc CPU > from host: 9, used: 13500, reserved: 0, actual total: 18616, total with > overprovisioning: 18616; requested cpu:1000,alloc_from_last_host?:false > ,considerReservedCapacity?: true > 2013-06-14 12:28:34,371 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) STATS: Can alloc MEM > from host: 9, used: 10066329600, reserved: 0, total: 37135881216; requested > mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true > 2013-06-14 12:28:34,371 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Found a suitable host, > adding to list: 9 > 2013-06-14 12:28:34,371 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Host Allocator returning > 1 suitable hosts > 2013-06-14 12:28:34,372 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Checking suitable pools for volume (Id, Type): > (129,ROOT) > 2013-06-14 12:28:34,372 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Volume is in READY state and has pool already > allocated, checking if pool can be reused, poolId: 203 > 2013-06-14 12:28:34,373 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Planner need not allocate a pool for this volume > since its READY > 2013-06-14 12:28:34,373 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Trying to find a potenial host and associated > storage pools from the suitable host/pool lists for this VM > 2013-06-14 12:28:34,373 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Checking if host: 9 can access any suitable > storage pool for volume: ROOT > 2013-06-14 12:28:34,373 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Host: 9 can access pool: 203 > 2013-06-14 12:28:34,373 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Found a potential host id: 9 name: > xenserver1.eu.manwin.local and associated storage pools for this VM > 2013-06-14 12:28:34,374 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Returning Deployment Destination: > Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] > : Dest[Zone(3)-Pod(3)-Cluster(3)-Host(9)-Storage()] > 2013-06-14 12:28:34,374 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Deployment found - P0=VM[User|i-2-107-VM], > P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] > : Dest[Zone(3)-Pod(3)-Cluster(3)-Host(9)-Storage()] > 2013-06-14 12:28:34,377 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) VM state transitted from :Starting to Starting > with event: OperationRetryvm's original host id: 9 new host id: 9 host id > before state transition: null > 2013-06-14 12:28:34,378 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) VM starting again on the last host it was stopped > on > 2013-06-14 12:28:34,380 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Hosts's actual total CPU: 18616 and CPU after > applying overprovisioning: 18616 > 2013-06-14 12:28:34,380 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) We are allocating VM, increasing the used > capacity of this host:9 > 2013-06-14 12:28:34,380 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Current Used CPU: 13500 , Free CPU:5116 > ,Requested CPU: 1000 > 2013-06-14 12:28:34,380 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Current Used RAM: 10066329600 , Free > RAM:27069551616 ,Requested RAM: 1073741824 > 2013-06-14 12:28:34,380 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) We are allocating VM to the last host again, so > adjusting the reserved capacity if it is not less than required > 2013-06-14 12:28:34,381 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Reserved CPU: 0 , Requested CPU: 1000 > 2013-06-14 12:28:34,381 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Reserved RAM: 0 , Requested RAM: 1073741824 > 2013-06-14 12:28:34,381 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) CPU STATS after allocation: for host: 9, old > used: 13500, old reserved: 0, actual total: 18616, total with > overprovisioning: 18616; new used:14500, reserved:0; requested > cpu:1000,alloc_from_last:true > 2013-06-14 12:28:34,381 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) RAM STATS after allocation: for host: 9, old > used: 10066329600, old reserved: 0, total: 37135881216; new used: > 11140071424, reserved: 0; requested mem: 1073741824,alloc_from_last:true > 2013-06-14 12:28:34,382 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) VM is being started in podId: 3 > 2013-06-14 12:28:34,384 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Network id=214 is already implemented > 2013-06-14 12:28:34,390 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Service SecurityGroup is not supported in the > network id=214 > 2013-06-14 12:28:34,394 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Changing active number of nics for network id=214 > on 1 > 2013-06-14 12:28:34,395 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking JuniperSRX to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:34,397 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking Netscaler to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:34,399 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking F5BigIp to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:34,400 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking VirtualRouter to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:34,406 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] > (Job-Executor-16:job-626) Starting a router for Ntwk[214|Guest|6] in > datacenter:com.cloud.dc.DataCenterVO$$EnhancerByCGLIB$$74446509@3 > 2013-06-14 12:28:34,415 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] > (Job-Executor-16:job-626) Applying dhcp entry in network Ntwk[214|Guest|6] > 2013-06-14 12:28:34,423 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017838: Sending { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"routing.DhcpEntryCommand":{"vmMac":"06:48:2e:00:00:a4","vmIpAddress":"10.4.16.121","vmName":"ubuntu1","defaultRouter":"10.4.16.65","defaultDns":"10.4.16.123","accessDetails":{"router.guest.ip":"10.4.16.123","zone.network.type":"Basic"," > router.name":"r-102-VM","router.ip":"169.254.3.42"},"wait":0}}] } > 2013-06-14 12:28:34,424 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017838: Executing: { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"routing.DhcpEntryCommand":{"vmMac":"06:48:2e:00:00:a4","vmIpAddress":"10.4.16.121","vmName":"ubuntu1","defaultRouter":"10.4.16.65","defaultDns":"10.4.16.123","accessDetails":{"router.guest.ip":"10.4.16.123","zone.network.type":"Basic"," > router.name":"r-102-VM","router.ip":"169.254.3.42"},"wait":0}}] } > 2013-06-14 12:28:37,832 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017838: Received: { Ans: , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 110, { Answer } } > 2013-06-14 12:28:37,832 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Cleanup succeeded. Details null > 2013-06-14 12:28:37,839 DEBUG > [network.router.VirtualNetworkApplianceManagerImpl] > (Job-Executor-16:job-626) Applying userdata and password entry in network > Ntwk[214|Guest|6] > 2013-06-14 12:28:37,845 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017839: Sending { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"routing.VmDataCommand":{"vmIpAddress":"10.4.16.121","vmName":"ubuntu1","accessDetails":{"router.guest.ip":"10.4.16.123","zone.network.type":"Basic","router.ip":"169.254.3.42"," > router.name":"r-102-VM"},"wait":0}}] } > 2013-06-14 12:28:37,846 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017839: Executing: { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"routing.VmDataCommand":{"vmIpAddress":"10.4.16.121","vmName":"ubuntu1","accessDetails":{"router.guest.ip":"10.4.16.123","zone.network.type":"Basic","router.ip":"169.254.3.42"," > router.name":"r-102-VM"},"wait":0}}] } > 2013-06-14 12:28:49,101 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017839: Received: { Ans: , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 110, { Answer } } > 2013-06-14 12:28:49,101 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Cleanup succeeded. Details null > 2013-06-14 12:28:49,101 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking Ovs to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:49,101 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking ExternalDhcpServer to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:49,103 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking BareMetal to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:49,103 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Asking SecurityGroupProvider to prepare for > Nic[171-107-3ee7e4d1-a732-4e6b-96d3-eb02caec4df3-10.4.16.121] > 2013-06-14 12:28:49,105 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Service SecurityGroup is not supported in the > network id=214 > 2013-06-14 12:28:49,106 DEBUG [cloud.storage.StorageManagerImpl] > (Job-Executor-16:job-626) Checking if we need to prepare 1 volumes for > VM[User|i-2-107-VM] > 2013-06-14 12:28:49,106 DEBUG [cloud.storage.StorageManagerImpl] > (Job-Executor-16:job-626) No need to recreate the volume: > Vol[129|vm=107|ROOT], since it already has a pool assigned: 203, adding > disk to VM > 2013-06-14 12:28:49,113 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017840: Sending { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"StartCommand":{"vm":{"id":107,"name":"i-2-107-VM","bootloader":"PyGrub","type":"User","cpus":1,"speed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Other > Ubuntu > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"7660f3d82965a6c7","params":{},"disks":[{"id":129,"name":"ROOT-107","mountPoint":"/mnt/san3/cloudstack/primary","path":"860f603b-36cd-465f-b447-b6a924d690bf","size":16106127360,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"7ec6e77f-76bb-3dca-a846-8b966be61006","deviceId":0},{"id":107,"name":"Ubuntu12.04 > (Manwin > EU)xxxx","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"ip":"10.4.16.121","netmask":"255.255.255.192","gateway":"10.4.16.65","mac":"06:48:2e:00:00:a4","dns1":"10.4.16.21","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false}]},"wait":0}}] > } > 2013-06-14 12:28:49,113 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017840: Executing: { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"StartCommand":{"vm":{"id":107,"name":"i-2-107-VM","bootloader":"PyGrub","type":"User","cpus":1,"speed":1000,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Other > Ubuntu > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"7660f3d82965a6c7","params":{},"disks":[{"id":129,"name":"ROOT-107","mountPoint":"/mnt/san3/cloudstack/primary","path":"860f603b-36cd-465f-b447-b6a924d690bf","size":16106127360,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"7ec6e77f-76bb-3dca-a846-8b966be61006","deviceId":0},{"id":107,"name":"Ubuntu12.04 > (Manwin > EU)xxxx","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"ip":"10.4.16.121","netmask":"255.255.255.192","gateway":"10.4.16.65","mac":"06:48:2e:00:00:a4","dns1":"10.4.16.21","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false}]},"wait":0}}] > } > 2013-06-14 12:28:59,317 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017840: Received: { Ans: , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 110, { StartAnswer } } > 2013-06-14 12:28:59,318 WARN [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Cleanup failed due to Unable to start i-2-107-VM > due to > 2013-06-14 12:28:59,321 INFO [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Unable to start VM on Host[-9-Routing] due to > Unable to start i-2-107-VM due to > 2013-06-14 12:28:59,322 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Cleaning up resources for the vm > VM[User|i-2-107-VM] in Starting state > 2013-06-14 12:28:59,323 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017841: Sending { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"StopCommand":{"isProxy":false,"vmName":"i-2-107-VM","wait":0}}] } > 2013-06-14 12:28:59,323 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017841: Executing: { Cmd , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 100111, > [{"StopCommand":{"isProxy":false,"vmName":"i-2-107-VM","wait":0}}] } > 2013-06-14 12:28:59,747 DEBUG [agent.transport.Request] > (Job-Executor-16:job-626) Seq 9-1193017841: Received: { Ans: , MgmtId: > 110492071566, via: 9, Ver: v1, Flags: 110, { StopAnswer } } > 2013-06-14 12:28:59,747 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Cleanup succeeded. Details VM does not exist > 2013-06-14 12:28:59,751 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Service SecurityGroup is not supported in the > network id=214 > 2013-06-14 12:28:59,754 DEBUG [cloud.network.NetworkManagerImpl] > (Job-Executor-16:job-626) Changing active number of nics for network id=214 > on -1 > 2013-06-14 12:28:59,755 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Successfully cleanued up resources for the vm > VM[User|i-2-107-VM] in Starting state > 2013-06-14 12:28:59,757 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Root volume is ready, need to place VM in > volume's cluster > 2013-06-14 12:28:59,757 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-16:job-626) Vol[129|vm=107|ROOT] is READY, changing > deployment plan to use this pool's dcId: 3 , podId: 3 , and clusterId: 3 > 2013-06-14 12:28:59,757 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) DeploymentPlanner allocation algorithm: random > 2013-06-14 12:28:59,758 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Trying to allocate a host and storage pools from > dc:3, pod:3,cluster:3, requested cpu: 1000, requested ram: 1073741824 > 2013-06-14 12:28:59,758 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Is ROOT volume READY (pool already allocated)?: > Yes > 2013-06-14 12:28:59,758 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) This VM has last host_id specified, trying to > choose the same host: 9 > 2013-06-14 12:28:59,759 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) The last host of this VM is in avoid set > 2013-06-14 12:28:59,759 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Cannot choose the last host to deploy this VM > 2013-06-14 12:28:59,759 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Searching resources only under specified Cluster: > 3 > 2013-06-14 12:28:59,762 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Checking resources in Cluster: 3 under Pod: 3 > 2013-06-14 12:28:59,762 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Calling HostAllocators to find suitable hosts > 2013-06-14 12:28:59,762 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Looking for hosts in dc: > 3 pod:3 cluster:3 > 2013-06-14 12:28:59,763 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) FirstFitAllocator has 1 > hosts to check for allocation: [Host[-9-Routing]] > 2013-06-14 12:28:59,765 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Found 1 hosts for > allocation after prioritization: [Host[-9-Routing]] > 2013-06-14 12:28:59,765 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Looking for > speed=1000Mhz, Ram=1024 > 2013-06-14 12:28:59,765 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Host name: > xenserver1.eu.manwin.local, hostId: 9 is in avoid set, skipping this and > trying other available hosts > 2013-06-14 12:28:59,765 DEBUG [allocator.impl.FirstFitAllocator] > (Job-Executor-16:job-626 FirstFitRoutingAllocator) Host Allocator returning > 0 suitable hosts > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) No suitable hosts found > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) No suitable hosts found under this Cluster: 3 > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Could not find suitable Deployment Destination > for this VM under any clusters, returning. > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) DeploymentPlanner allocation algorithm: random > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Trying to allocate a host and storage pools from > dc:3, pod:3,cluster:null, requested cpu: 1000, requested ram: 1073741824 > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Is ROOT volume READY (pool already allocated)?: No > 2013-06-14 12:28:59,765 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) This VM has last host_id specified, trying to > choose the same host: 9 > 2013-06-14 12:28:59,766 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) The last host of this VM is in avoid set > 2013-06-14 12:28:59,766 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Cannot choose the last host to deploy this VM > 2013-06-14 12:28:59,766 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Searching resources only under specified Pod: 3 > 2013-06-14 12:28:59,768 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Listing clusters in order of aggregate capacity, > that have (atleast one host with) enough CPU and RAM capacity under this > Pod: 3 > 2013-06-14 12:28:59,768 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) CPUOverprovisioningFactor considered: 1.0 > 2013-06-14 12:28:59,770 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) Removing from the clusterId list these clusters > from avoid set: [3] > 2013-06-14 12:28:59,770 DEBUG [cloud.deploy.FirstFitPlanner] > (Job-Executor-16:job-626) No clusters found after removing disabled > clusters and clusters in avoid list, returning. > 2013-06-14 12:28:59,773 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) VM state transitted from :Starting to Stopped > with event: OperationFailedvm's original host id: 9 new host id: null host > id before state transition: 9 > 2013-06-14 12:28:59,775 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) Hosts's actual total CPU: 18616 and CPU after > applying overprovisioning: 18616 > 2013-06-14 12:28:59,775 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) release cpu from host: 9, old used: > 14500,reserved: 0, actual total: 18616, total with overprovisioning: 18616; > new used: 13500,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-06-14 12:28:59,775 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-16:job-626) release mem from host: 9, old used: > 11140071424,reserved: 0, total: 37135881216; new used: > 10066329600,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-06-14 12:28:59,779 INFO [cloud.api.ApiDispatcher] > (Job-Executor-16:job-626) Unable to create a deployment for > VM[User|i-2-107-VM] > 2013-06-14 12:28:59,779 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-16:job-626) Complete async job-626, jobStatus: 2, resultCode: > 530, result: com.cloud.api.response.ExceptionResponse@23a1eaf3 > 2013-06-14 12:29:04,397 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-21:null) Async job-626 completed > ############################################################################################################################################################################################################ > > > Great thanks, > William > > > > -----Original Message----- > From: Nitin Mehta [mailto:nitin.me...@citrix.com] > Sent: June-18-13 12:02 PM > To: dev@cloudstack.apache.org; us...@cloudstack.apache.org > Subject: Re: starting VM and get error of "unable to create a deployment > for VM[user|i-2-107-VM]" > > Can you check the hypervisor admin guide to see if this version of guest > os is supported ? > Also can u please paste the complete logs (grep for job-626 would work as > well) > > On 18/06/13 8:15 PM, "William Jiang" <william.ji...@manwin.com> wrote: > > >Hi, > > > >We have a Ubuntu 12.04 VM with one disk on shared storage, it was > >working well before but now we saw the error of "unable to create a > >deployment for VM[user|i-2-107-VM]" during starting. > >We saw this kind of issue happened on a windows server 2008 VM before. > > > >In /var/log/cloud/management/management-server.log > >We got following errors: > > > >2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > >(Job-Executor-16:job-626) We need to allocate to the last host again, > >so checking if there is enough reserved capacity > >2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > >(Job-Executor-16:job-626) Reserved CPU: 0 , Requested CPU: 1000 > >2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > >(Job-Executor-16:job-626) Reserved RAM: 0 , Requested RAM: 1073741824 > >2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > >(Job-Executor-16:job-626) STATS: Failed to alloc resource from host: 9 > >reservedCpu: 0, requested cpu: 1000, reservedMem: 0, requested mem: > >1073741824 > >2013-06-14 12:28:34,362 DEBUG [cloud.capacity.CapacityManagerImpl] > >(Job-Executor-16:job-626) Host does not have enough reserved CPU > >available, cannot allocate to this host. > >2013-06-14 12:28:34,362 DEBUG [cloud.deploy.FirstFitPlanner] > >(Job-Executor-16:job-626) The last host of this VM does not have enough > >capacity > >2013-06-14 12:28:34,362 DEBUG [cloud.deploy.FirstFitPlanner] > >(Job-Executor-16:job-626) Cannot choose the last host to deploy this VM > > > >Any ideas about this issue? > > > >Thanks, > >William > >This e-mail may be privileged and/or confidential, and the sender does > >not waive any related rights and obligations. Any distribution, use or > >copying of this e-mail or the information it contains by other than an > >intended recipient is unauthorized. If you received this e-mail in > >error, please advise me (by return e-mail or otherwise) immediately. Ce > >courrier ?lectronique est confidentiel et prot?g?. L'exp?diteur ne > >renonce pas aux droits et obligations qui s'y rapportent. Toute > >diffusion, utilisation ou copie de ce message ou des renseignements > >qu'il contient par une personne autre que le (les) destinataire(s) > >d?sign?(s) est interdite. Si vous recevez ce courrier ?lectronique par > >erreur, veuillez m'en aviser imm?diatement, par retour de courrier > ?lectronique ou par un autre moyen. > > This e-mail may be privileged and/or confidential, and the sender does not > waive any related rights and obligations. Any distribution, use or copying > of this e-mail or the information it contains by other than an intended > recipient is unauthorized. If you received this e-mail in error, please > advise me (by return e-mail or otherwise) immediately. Ce courrier > électronique est confidentiel et protégé. L'expéditeur ne renonce pas aux > droits et obligations qui s'y rapportent. Toute diffusion, utilisation ou > copie de ce message ou des renseignements qu'il contient par une personne > autre que le (les) destinataire(s) désigné(s) est interdite. Si vous > recevez ce courrier électronique par erreur, veuillez m'en aviser > immédiatement, par retour de courrier électronique ou par un autre moyen. > This e-mail may be privileged and/or confidential, and the sender does not > waive any related rights and obligations. Any distribution, use or copying > of this e-mail or the information it contains by other than an intended > recipient is unauthorized. If you received this e-mail in error, please > advise me (by return e-mail or otherwise) immediately. Ce courrier > électronique est confidentiel et protégé. L'expéditeur ne renonce pas aux > droits et obligations qui s'y rapportent. Toute diffusion, utilisation ou > copie de ce message ou des renseignements qu'il contient par une personne > autre que le (les) destinataire(s) désigné(s) est interdite. Si vous > recevez ce courrier électronique par erreur, veuillez m'en aviser > immédiatement, par retour de courrier électronique ou par un autre moyen. >
