Abhinav Roy created CLOUDSTACK-4145:
---------------------------------------
Summary: [upgrade][2.2.13 -> 2.2.14 -> 4.2][KVM] After upgrade not
able to start/create user VMs
Key: CLOUDSTACK-4145
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4145
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: KVM, Management Server, Upgrade
Affects Versions: 4.2.0
Environment: upgrade from 2.2.13 (rhel 6.1 build) -> 2.2.14 (rhel 6.1
build) -> 4.2 (rhel 6.2 build)
MS : CentOS 6.1
KVM : CentOS 6.1
Reporter: Abhinav Roy
Priority: Blocker
Fix For: 4.2.0
Steps :
====================
1. Deploy CS 2.2.13 advanced zone setup with KVM.
2. Create VMs, template,snapshots, domains, accounts etc
3. Upgrade the management server and agent to 2.2.14
4. Create VMs , templates, snapshots, domain, accounts etc.
5. Have some VMs in stopped state
6. Upgrade the management server and agent to 4.2
Expected behaviour :
===================
After upgrade we should be able to start the stopped vms and also able to
create new user VMs
Observed behaviour:
===================
1. After upgrade I was able to start/stop system vms and they started with the
latest 4.2 iso.
2. I was able to restart the routers.
3. I was able to create routers for new networks also.
4. But i was not able to start the stopped vms or create new user vms.
2013-08-07 16:27:34,017 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) copyAsync
inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2013-08-07 16:27:34,030 DEBUG [agent.transport.Request] (Job-Executor-2:job-57
= [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699689: Sending { Cmd ,
MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641","origUrl":"http://10.147.28.7/templates/Windows2008/Windows2008R2server64bitrhel61.qcow2","uuid":"202","id":202,"format":"QCOW2","accountId":2,"hvm":true,"displayText":"win2k8","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0","id":201,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/abhinav/kvm-pri2","port":2049}},"name":"202-2-b62c2b0c-6d69-3456-8312-d21de33aab57","hypervisorType":"KVM"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"5bc6e87f-0d13-466d-abf1-893388f455bb","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0","id":201,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/abhinav/kvm-pri2","port":2049}},"name":"ROOT-27","size":32212254720,"volumeId":32,"vmName":"i-2-27-VM","accountId":2,"format":"QCOW2","id":32,"hypervisorType":"None"}},"executeInSequence":false,"wait":0}}]
}
2013-08-07 16:27:34,092 DEBUG [agent.transport.Request]
(AgentManager-Handler-5:null) Seq 3-1516699689: Processing: { Ans: , MgmtId:
226870599129537, via: 3, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name
'/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641'","wait":0}}]
}
2013-08-07 16:27:34,092 DEBUG [agent.transport.Request] (Job-Executor-2:job-57
= [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699689: Received: { Ans:
, MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-08-07 16:27:34,099 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unsupported
data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@6ca8a7af), no need
to delete from object in store ref table
2013-08-07 16:27:34,099 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to
create Vol[32|vm=27|ROOT]:com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name
'/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641'
2013-08-07 16:27:34,099 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to
contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:201] is
unreachable: Unable to create
Vol[32|vm=27|ROOT]:com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name
'/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641'
at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2502)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2551)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:934)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:624)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3408)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2968)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2954)
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:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:636)
2013-08-07 16:27:34,105 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Cleaning up
resources for the vm VM[User|vnew-2k8-402] in Starting state
2013-08-07 16:27:34,108 DEBUG [agent.transport.Request] (Job-Executor-2:job-57
= [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699690: Sending { Cmd ,
MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-27-VM","wait":0}}]
}
2013-08-07 16:27:34,285 DEBUG [agent.transport.Request]
(AgentManager-Handler-6:null) Seq 3-1516699690: Processing: { Ans: , MgmtId:
226870599129537, via: 3, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-08-07 16:27:34,285 DEBUG [agent.transport.Request] (Job-Executor-2:job-57
= [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699690: Received: { Ans:
, MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 10, { StopAnswer } }
2013-08-07 16:27:34,297 DEBUG [cloud.network.NetworkModelImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Service
SecurityGroup is not supported in the network id=206
2013-08-07 16:27:34,301 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Changing
active number of nics for network id=206 on -1
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
JuniperSRX to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
Netscaler to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
F5BigIP to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
CiscoNexus1000vVSM to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
CiscoVNMC to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
NiciraNvp to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,306 DEBUG [network.element.NiciraNvpElement]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Checking if
NiciraNvpElement can handle service Connectivity on network new network
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
VirtualRouter to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Ovs
to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
SecurityGroupProvider to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
VpcVirtualRouter to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
InternalLbVm to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
BareMetalDhcp to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
BareMetalPxe to release Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking
BareMetalUserdata to release
Nic[55-27-ca2300ae-a8e8-48dc-9081-0c990b550239-10.1.1.9]
2013-08-07 16:27:34,308 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Successfully
released network resources for the vm VM[User|vnew-2k8-402]
2013-08-07 16:27:34,308 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Successfully
cleanued up resources for the vm VM[User|vnew-2k8-402] in Starting state
2013-08-07 16:27:34,321 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Deploy
avoids pods: null, clusters: null, hosts: [3]
2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ])
DeploymentPlanner allocation algorithm:
com.cloud.deploy.UserConcentratedPodPlanner_EnhancerByCloudStack_1f122a17@5b12bba0
2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Trying to
allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu:
500, requested ram: 536870912
2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Is ROOT
volume READY (pool already allocated)?: No
2013-08-07 16:27:34,323 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ])
DeploymentPlan has host_id specified, choosing this host and making no checks
on this host: 3
2013-08-07 16:27:34,325 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) The
specified host is in avoid set
2013-08-07 16:27:34,325 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Cannnot
deploy to specified host, returning.
2013-08-07 16:27:34,365 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state
transitted from :Starting to Stopped with event: OperationFailedvm's original
host id: null new host id: null host id before state transition: 3
2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Hosts's
actual total CPU: 9576 and CPU after applying overprovisioning: 9576
2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Hosts's
actual total RAM: 8243073024 and RAM after applying overprovisioning: 8243073024
2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) release cpu
from host: 3, old used: 6000,reserved: 1000, actual total: 9576, total with
overprovisioning: 9576; new used: 5500,reserved:1000; movedfromreserved:
false,moveToReserveredfalse
2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) release mem
from host: 3, old used: 5502926848,reserved: 1073741824, total: 8243073024; new
used: 4966055936,reserved:1073741824; movedfromreserved:
false,moveToReserveredfalse
2013-08-07 16:27:34,421 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state
transitted from :Stopped to Starting with event: StartRequestedvm's original
host id: null new host id: null host id before state transition: null
2013-08-07 16:27:34,421 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Successfully
transitioned to start state for VM[User|vnew-2k8-402] reservation id =
ef1819ff-9f8e-46f9-b132-ef4cf53b5159
2013-08-07 16:27:34,426 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Trying to
deploy VM, vm has dcId: 1 and podId: 1
2013-08-07 16:27:34,426 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Deploy
avoids pods: null, clusters: null, hosts: [3]
2013-08-07 16:27:34,439 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Deploy
avoids pods: null, clusters: null, hosts: [3]
2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ])
DeploymentPlanner allocation algorithm:
com.cloud.deploy.UserConcentratedPodPlanner_EnhancerByCloudStack_1f122a17@5b12bba0
2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Trying to
allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu:
500, requested ram: 536870912
2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Is ROOT
volume READY (pool already allocated)?: No
2013-08-07 16:27:34,441 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Searching
resources only under specified Pod: 1
2013-08-07 16:27:34,441 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Listing
clusters in order of aggregate capacity, that have (atleast one host with)
enough CPU and RAM capacity under this Pod: 1
2013-08-07 16:27:34,451 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Checking
resources in Cluster: 1 under Pod: 1
2013-08-07 16:27:34,451 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-08-07 16:27:34,456 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
allocation: [Host[-3-Routing]]
2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization:
[Host[-3-Routing]]
2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) Host name: centos61-band28, hostId: 3 is in avoid
set, skipping this and trying other available hosts
2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]
FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2013-08-07 16:27:34,459 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) No suitable
hosts found
2013-08-07 16:27:34,459 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) No suitable
hosts found under this Cluster: 1
2013-08-07 16:27:34,464 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Could not
find suitable Deployment Destination for this VM under any clusters, returning.
2013-08-07 16:27:34,464 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Searching
resources only under specified Pod: 1
2013-08-07 16:27:34,464 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Listing
clusters in order of aggregate capacity, that have (atleast one host with)
enough CPU and RAM capacity under this Pod: 1
2013-08-07 16:27:34,468 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Removing
from the clusterId list these clusters from avoid set: [1]
2013-08-07 16:27:34,468 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) No clusters
found after removing disabled clusters and clusters in avoid list, returning.
2013-08-07 16:27:34,481 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state
transitted from :Starting to Stopped with event: OperationFailedvm's original
host id: null new host id: null host id before state transition: null
2013-08-07 16:27:34,509 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Destroying
vm VM[User|vnew-2k8-402] as it failed to create on Host with Id:null
2013-08-07 16:27:34,522 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) 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
2013-08-07 16:27:34,530 WARN [apache.cloudstack.alerts] (Job-Executor-2:job-57
= [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) alertType:: 8 // dataCenterId:: 1
// podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 27,
on Host with Id: null
2013-08-07 16:27:34,583 INFO [user.vm.DeployVMCmd] (Job-Executor-2:job-57 = [
3108142a-644b-4466-9ed0-b8d5d22f3fcc ])
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|vnew-2k8-402]Scope=interface com.cloud.dc.DataCenter;
id=1
2013-08-07 16:27:34,584 INFO [user.vm.DeployVMCmd] (Job-Executor-2:job-57 = [
3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to create a deployment for
VM[User|vnew-2k8-402]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|vnew-2k8-402]Scope=interface com.cloud.dc.DataCenter;
id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:624)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3408)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2968)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2954)
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:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:636)
2013-08-07 16:27:34,586 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-2:job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Complete
async job-57 = [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ], jobStatus: 2,
resultCode: 530, result: Error Code: 533 Error text: Unable to create a
deployment for VM[User|vnew-2k8-402]
In the error it says Storage volume not found: no storage vol with matching
name
'/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641'
........... but i was able to find the same on KVM host
[root@centos61-band28 ~]# ls
/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641
/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641
[root@centos61-band28 ~]#
NOTE : When you check the DB dumps , please don't go by the current state where
all router vms and user vms are stopped. They were all in up state initially
but then after an hour or so suddenly my host went to disconnected state and
after i restarted agent on the host and it came up but by then all user vms
went to stopped state.
Attaching all DB dumps, agent logs and management server logs.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
