The error seems to be somewhere between these logs. Are there more logs in between these ones ? Also are you hitting it consistently ? Retry and also check XS logs 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:a 4","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,"na me":"ROOT-107","mountPoint":"/mnt/san3/cloudstack/primary","path":"860f603b -36cd-465f-b447-b6a924d690bf","size":16106127360,"type":"ROOT","storagePool Type":"NetworkFilesystem","storagePoolUuid":"7ec6e77f-76bb-3dca-a846-8b966b e61006","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:a 4","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
On 19/06/13 9:07 PM, "William Jiang" <william.ji...@manwin.com> wrote: >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.net >>work.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.net >>work.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":"Ba >>sic","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":"Ba >>sic","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.