Hi, There is no agent log on management server /var/log/cloud/agent, do I need manually enable it ?
Thanks, William -----Original Message----- From: Wei ZHOU [mailto:ustcweiz...@gmail.com] Sent: June-19-13 10:25 AM To: dev@cloudstack.apache.org Subject: Re: starting VM and get error of "unable to create a deployment for VM[user|i-2-107-VM]" 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","sessio > nkey":"eihe8Buev1Ale+nhxw+w1nqQ\u003d","ctxUserId":"2","_":"1371227586 > 576","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-->Po > ol(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":"PyG > rub","type":"User","cpus":1,"speed":1000,"minRam":1073741824,"maxRam": > 1073741824,"arch":"x86_64","os":"Other > Ubuntu > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitC > puUse":false,"vncPassword":"7660f3d82965a6c7","params":{},"disks":[{"i > d":129,"name":"ROOT-107","mountPoint":"/mnt/san3/cloudstack/primary"," > path":"860f603b-36cd-465f-b447-b6a924d690bf","size":16106127360,"type" > :"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"7ec6e > 77f-76bb-3dca-a846-8b966be61006","deviceId":0},{"id":107,"name":"Ubunt > u12.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":"0 > 6:48:2e:00:00:a4","dns1":"10.4.16.21","broadcastType":"Vlan","type":"G > uest","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":"PyG > rub","type":"User","cpus":1,"speed":1000,"minRam":1073741824,"maxRam": > 1073741824,"arch":"x86_64","os":"Other > Ubuntu > (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitC > puUse":false,"vncPassword":"7660f3d82965a6c7","params":{},"disks":[{"i > d":129,"name":"ROOT-107","mountPoint":"/mnt/san3/cloudstack/primary"," > path":"860f603b-36cd-465f-b447-b6a924d690bf","size":16106127360,"type" > :"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"7ec6e > 77f-76bb-3dca-a846-8b966be61006","deviceId":0},{"id":107,"name":"Ubunt > u12.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":"0 > 6:48:2e:00:00:a4","dns1":"10.4.16.21","broadcastType":"Vlan","type":"G > uest","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. > 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.
