Hello guys,
Was wondering if someone could help me with a strange issue that I am having
with XenServer 6.2 and ACS 4.2.1.
I've recently added a new XenServer 6.2 cluster to my existing ACS + KVM
setup.I've created a new system and disk offerings using tag "xenserver". I've
also added this tag to the xenserver host and the nfs primary storage. I have
verified that the setup works by successfully creating and staring several vms
which are connected to an existing ACS guest network that I have setup for
testing. All test vms are being created and started and I can successfully
login to them.
Having said this, I am, however, unable to create any guest vms on the
XenServer if I choose to create a new guest network from the Add Instance
wizard. The guest vm is created with status Error and the management server
logs show the error that I am pasting at the end of this email. From what I can
see, the new network is created with status Allocated and I can see it under
the Network section. I do not, however, see a virtual router corresponding to
that network.
>From the management server log I can see the following, which looks very odd
>and completely untrue (as I can successfully create a number of vms using the
>same system and disk offering using a pre-created guest network. I've double
>checked that the XenServer host has the tag "xenserver"):
2014-06-11 16:16:25,312 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Looking for hosts having tag specified on
SvcOffering:xenserver
2014-06-11 16:16:25,314 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Hosts with tag 'xenserver' are:[]
Any idea what is going on?
Management Server Log:
2014-06-11 16:16:24,962 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
===START=== 192.168.169.91 -- GET command=createNetwork&response=json&se
ssionkey=6q8QippP1uE3Jd%2BWL8FuA9xcTfM%3D&networkOfferingId=87e090cb-a134-4d77-b664-ef3858a52f3c&name=XenServer-Network-Test-3&displayText=XenServer-N
etwork-Test-3&zoneId=b8c25216-4c2d-4d01-87d8-3673c0ba9780&_=1402499785135
2014-06-11 16:16:25,015 DEBUG [network.guru.NiciraNvpGuestNetworkGuru]
(catalina-exec-6:null) Refusing to design this network
2014-06-11 16:16:25,015 DEBUG [network.guru.MidoNetGuestNetworkGuru]
(catalina-exec-6:null) design called
2014-06-11 16:16:25,016 DEBUG [network.guru.MidoNetGuestNetworkGuru]
(catalina-exec-6:null) Refusing to design this network, the physical isolation
ty
pe is not MIDO
2014-06-11 16:16:25,017 DEBUG [network.guru.SspGuestNetworkGuru]
(catalina-exec-6:null) SSP not configured to be active
2014-06-11 16:16:25,017 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-6:null) Releasing lock for
Acct[06eedc2c-65f2-11e3-9bd1-d8d38559b2d0-a
dmin]
2014-06-11 16:16:25,039 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
===END=== 192.168.169.91 -- GET command=createNetwork&response=json&sess
ionkey=6q8QippP1uE3Jd%2BWL8FuA9xcTfM%3D&networkOfferingId=87e090cb-a134-4d77-b664-ef3858a52f3c&name=XenServer-Network-Test-3&displayText=XenServer-Net
work-Test-3&zoneId=b8c25216-4c2d-4d01-87d8-3673c0ba9780&_=1402499785135
2014-06-11 16:16:25,133 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null)
===START=== 192.168.169.91 -- GET
command=deployVirtualMachine&zoneId=b8c25216-4c2d-4d01-87d8-3673c0ba9780&templateId=677c5335-7224-4ce7-b5e9-da70e89a6f99&hypervisor=KVM&serviceOfferingId=62f076eb-fbae-485d-aa78-e7e4c9717346&diskOfferingId=cbc5779b-7de3-4f6b-90d0-304029f59364&size=10&networkIds=48c669d0-0e41-40b3-be7d-b6078ff98cff&displayname=ubuntu-xen-test-4&name=ubuntu-xen-test-4&response=json&sessionkey=6q8QippP1uE3Jd%2BWL8FuA9xcTfM%3D&_=1402499785306
2014-06-11 16:16:25,140 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-7:null)
InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-06-11 16:16:25,142 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-7:null)
ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-06-11 16:16:25,144 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-7:null)
ControlledEntity name is:com.cloud.network.Network
2014-06-11 16:16:25,148 DEBUG [cloud.api.ApiDispatcher] (catalina-exec-7:null)
InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-06-11 16:16:25,157 DEBUG [cloud.network.NetworkModelImpl]
(catalina-exec-7:null) Service SecurityGroup is not supported in the network
id=279
2014-06-11 16:16:25,168 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-7:null) Allocating in the DB for vm
2014-06-11 16:16:25,178 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-7:null) Allocating entries for VM: VM[User|ubuntu-xen-test-4]
2014-06-11 16:16:25,178 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-7:null) Allocating nics for VM[User|ubuntu-xen-test-4]
2014-06-11 16:16:25,179 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-7:null) Allocating nic for vm VM[User|ubuntu-xen-test-4] in
network Ntwk[279|Guest|8] with requested profile NicProfile[0-0-null-null-null
2014-06-11 16:16:25,190 DEBUG [cloud.network.NetworkModelImpl]
(catalina-exec-7:null) Service SecurityGroup is not supported in the network
id=279
2014-06-11 16:16:25,191 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-7:null) Allocating disks for VM[User|ubuntu-xen-test-4]
2014-06-11 16:16:25,199 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-7:null) Allocation completed for VM: VM[User|ubuntu-xen-test-4]
2014-06-11 16:16:25,199 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-7:null) Successfully allocated DB entry for
VM[User|ubuntu-xen-test-4]
2014-06-11 16:16:25,217 DEBUG [cloud.network.NetworkModelImpl]
(catalina-exec-7:null) Service SecurityGroup is not supported in the network
id=279
2014-06-11 16:16:25,219 DEBUG [cloud.network.NetworkModelImpl]
(catalina-exec-7:null) Service SecurityGroup is not supported in the network
id=279
2014-06-11 16:16:25,231 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-7:null) submit async job-5195 = [
10d345f9-2fb2-42ef-850f-4919512d63db ], details: AsyncJobVO {id:5195, userId:
3, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId:
838, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdOriginator:
null, cmdInfo:
{"sessionkey":"6q8QippP1uE3Jd+WL8FuA9xcTfM\u003d","cmdEventType":"VM.CREATE","ctxUserId":"3","serviceOfferingId":"62f076eb-fbae-485d-aa78-e7e4c9717346","httpmethod":"GET","size":"10","zoneId":"b8c25216-4c2d-4d01-87d8-3673c0ba9780","id":"838","response":"json","templateId":"677c5335-7224-4ce7-b5e9-da70e89a6f99","networkIds":"48c669d0-0e41-40b3-be7d-b6078ff98cff","hypervisor":"KVM","name":"ubuntu-xen-test-4","diskOfferingId":"cbc5779b-7de3-4f6b-90d0-304029f59364","_":"1402499785306","ctxAccountId":"2","ctxStartEventId":"16816","displayname":"ubuntu-xen-test-4"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 115129173025114,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-11 16:16:25,239 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-5195 = [
10d345f9-2fb2-42ef-850f-4919512d63db ]
2014-06-11 16:16:25,240 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null)
===END=== 192.168.169.91 -- GET
command=deployVirtualMachine&zoneId=b8c25216-4c2d-4d01-87d8-3673c0ba9780&templateId=677c5335-7224-4ce7-b5e9-da70e89a6f99&hypervisor=KVM&serviceOfferingId=62f076eb-fbae-485d-aa78-e7e4c9717346&diskOfferingId=cbc5779b-7de3-4f6b-90d0-304029f59364&size=10&networkIds=48c669d0-0e41-40b3-be7d-b6078ff98cff&displayname=ubuntu-xen-test-4&name=ubuntu-xen-test-4&response=json&sessionkey=6q8QippP1uE3Jd%2BWL8FuA9xcTfM%3D&_=1402499785306
2014-06-11 16:16:25,245 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-06-11 16:16:25,248 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-06-11 16:16:25,251 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
ControlledEntity name is:com.cloud.network.Network
2014-06-11 16:16:25,254 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-06-11 16:16:25,285 DEBUG [cloud.network.NetworkModelImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Service
SecurityGroup is not supported in the network id=279
2014-06-11 16:16:25,288 DEBUG [cloud.network.NetworkModelImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Service
SecurityGroup is not supported in the network id=279
2014-06-11 16:16:25,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Deploy
avoids pods: [], clusters: [], hosts: []
2014-06-11 16:16:25,301 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_642d2956@3002f352
2014-06-11 16:16:25,301 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Trying to
allocate a host and storage pools from dc:1, pod:null,cluster:null, requested
cpu: 2000, requested ram: 1073741824
2014-06-11 16:16:25,301 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Is ROOT
volume READY (pool already allocated)?: No
2014-06-11 16:16:25,301 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Searching
all possible resources under this Zone: 1
2014-06-11 16:16:25,302 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Listing
clusters in order of aggregate capacity, that have (atleast one host with)
enough CPU and RAM capacity under this Zone: 1
2014-06-11 16:16:25,304 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Removing
from the clusterId list these clusters from avoid set: []
2014-06-11 16:16:25,310 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Cluster:
4 has HyperVisorType that does not match the VM, skipping this cluster
2014-06-11 16:16:25,311 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Checking
resources in Cluster: 1 under Pod: 1
2014-06-11 16:16:25,312 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2014-06-11 16:16:25,312 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Looking for hosts having tag specified on
SvcOffering:xenserver
2014-06-11 16:16:25,314 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Hosts with tag 'xenserver' are:[]
2014-06-11 16:16:25,315 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) FirstFitAllocator has 0 hosts to check for
allocation: []
2014-06-11 16:16:25,317 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Found 0 hosts for allocation after prioritization: []
2014-06-11 16:16:25,317 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Looking for speed=2000Mhz, Ram=1024
2014-06-11 16:16:25,317 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]
FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2014-06-11 16:16:25,317 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) No
suitable hosts found
2014-06-11 16:16:25,317 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) No
suitable hosts found under this Cluster: 1
2014-06-11 16:16:25,318 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Could not
find suitable Deployment Destination for this VM under any clusters, returning.
2014-06-11 16:16:25,319 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Searching
all possible resources under this Zone: 1
2014-06-11 16:16:25,319 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Listing
clusters in order of aggregate capacity, that have (atleast one host with)
enough CPU and RAM capacity under this Zone: 1
2014-06-11 16:16:25,321 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Removing
from the clusterId list these clusters from avoid set: [1, 4]
2014-06-11 16:16:25,322 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) No
clusters found after removing disabled clusters and clusters in avoid list,
returning.
2014-06-11 16:16:25,324 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
Destroying vm VM[User|ubuntu-xen-test-4] as it failed to create on Host with
Id:null
2014-06-11 16:16:25,330 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) VM state
transitted from :Stopped to Error with event: OperationFailedToErrorvm's
original host id: null new host id: null host id before state transition: null
2014-06-11 16:16:25,336 WARN [apache.cloudstack.alerts]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ])
alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null //
message:: Failed to deploy Vm with Id: 838, on Host with Id: null
2014-06-11 16:16:25,359 INFO [user.vm.DeployVMCmd] (Job-Executor-76:job-5195 =
[ 10d345f9-2fb2-42ef-850f-4919512d63db ])
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|ubuntu-xen-test-4]Scope=interface
com.cloud.dc.DataCenter; id=1
2014-06-11 16:16:25,359 INFO [user.vm.DeployVMCmd] (Job-Executor-76:job-5195 =
[ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Unable to create a deployment for
VM[User|ubuntu-xen-test-4]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|ubuntu-xen-test-4]Scope=interface
com.cloud.dc.DataCenter; id=1
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:209)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3439)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3000)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2986)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2014-06-11 16:16:25,360 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-76:job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ]) Complete
async job-5195 = [ 10d345f9-2fb2-42ef-850f-4919512d63db ], jobStatus: 2,
resultCode: 530, result: Error Code: 533 Error text: Unable to create a
deployment for VM[User|ubuntu-xen-test-4]
Cheers
Andrei
