Hi Nitin,
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.
