Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id E24B8109A0 for ; Mon, 19 Aug 2013 20:59:48 +0000 (UTC) Received: (qmail 8920 invoked by uid 500); 19 Aug 2013 20:59:48 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 8902 invoked by uid 500); 19 Aug 2013 20:59:48 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 8895 invoked by uid 500); 19 Aug 2013 20:59:48 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 8891 invoked by uid 99); 19 Aug 2013 20:59:48 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 19 Aug 2013 20:59:48 +0000 Date: Mon, 19 Aug 2013 20:59:48 +0000 (UTC) From: "Abhinav Roy (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Closed] (CLOUDSTACK-4145) [upgrade][2.2.13 -> 2.2.14 -> 4.2][KVM] After upgrade not able to start/create user VMs MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-4145?page=3Dcom.atl= assian.jira.plugin.system.issuetabpanels:all-tabpanel ] Abhinav Roy closed CLOUDSTACK-4145. ----------------------------------- closing the issue after fix validation =20 > [upgrade][2.2.13 -> 2.2.14 -> 4.2][KVM] After upgrade not able to start/c= reate user VMs > -------------------------------------------------------------------------= -------------- > > Key: CLOUDSTACK-4145 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-414= 5 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > 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 > Assignee: Rajesh Battala > Priority: Blocker > Fix For: 4.2.0 > > Attachments: CS-4145.zip > > > Steps : > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 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 : > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > After upgrade we should be able to start the stopped vms and also able to= create new user VMs > Observed behaviour: > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 1. After upgrade I was able to start/stop system vms and they started wit= h 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) copyAs= ync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME > 2013-08-07 16:27:34,030 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699689: Sendi= ng { Cmd , MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 100011, [{"org= .apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloud= stack.storage.to.TemplateObjectTO":{"path":"/mnt/9fb7c84b-bfff-3ca2-9fc0-f5= 0181c6b1f0/2f032a82-d189-4587-9a93-41ee1f864641","origUrl":"http://10.147.2= 8.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":"NetworkFi= lesystem","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":{"uui= d":"5bc6e87f-0d13-466d-abf1-893388f455bb","volumeType":"ROOT","dataStore":{= "org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9fb7c84b-bff= f-3ca2-9fc0-f50181c6b1f0","id":201,"poolType":"NetworkFilesystem","host":"1= 0.102.192.100","path":"/cpg_vol/abhinav/kvm-pri2","port":2049}},"name":"ROO= T-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-Han= dler-5:null) Seq 3-1516699689: Processing: { Ans: , MgmtId: 22687059912953= 7, via: 3, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.Cop= yCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRunti= meException: org.libvirt.LibvirtException: Storage volume not found: no sto= rage vol with matching name '/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f03= 2a82-d189-4587-9a93-41ee1f864641'","wait":0}}] } > 2013-08-07 16:27:34,092 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699689: Recei= ved: { Ans: , MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 10, { CopyC= mdAnswer } } > 2013-08-07 16:27:34,099 WARN [storage.datastore.ObjectInDataStoreManager= Impl] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) = Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.Pr= imaryDataStoreImpl@6ca8a7af), no need to delete from object in store ref ta= ble > 2013-08-07 16:27:34,099 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Exec= utor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to creat= e Vol[32|vm=3D27|ROOT]:com.cloud.utils.exception.CloudRuntimeException: org= .libvirt.LibvirtException: Storage volume not found: no storage vol with ma= tching name '/mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9= a93-41ee1f864641' > 2013-08-07 16:27:34,099 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to co= ntact resource. > com.cloud.exception.StorageUnavailableException: Resource [StoragePool:20= 1] is unreachable: Unable to create Vol[32|vm=3D27|ROOT]:com.cloud.utils.ex= ception.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(VolumeManag= erImpl.java:2502) > at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.= java:2551) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMac= hineManagerImpl.java:934) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineMan= agerImpl.java:624) > at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerI= mpl.deployVirtualMachine(VMEntityManagerImpl.java:227) > at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEn= tityImpl.deploy(VirtualMachineEntityImpl.java:209) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:3408) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:2968) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:2954) > at com.cloud.utils.component.ComponentInstantiationPostProcessor$= InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:12= 5) > 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(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:603) > at java.lang.Thread.run(Thread.java:636) > 2013-08-07 16:27:34,105 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 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:j= ob-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699690: Sendi= ng { Cmd , MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 100011, [{"com= .cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"v= mName":"i-2-27-VM","wait":0}}] } > 2013-08-07 16:27:34,285 DEBUG [agent.transport.Request] (AgentManager-Han= dler-6:null) Seq 3-1516699690: Processing: { Ans: , MgmtId: 22687059912953= 7, 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:j= ob-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Seq 3-1516699690: Recei= ved: { Ans: , MgmtId: 226870599129537, via: 3, Ver: v1, Flags: 10, { StopA= nswer } } > 2013-08-07 16:27:34,297 DEBUG [cloud.network.NetworkModelImpl] (Job-Execu= tor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Service Security= Group is not supported in the network id=3D206 > 2013-08-07 16:27:34,301 DEBUG [cloud.network.NetworkManagerImpl] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Changing activ= e number of nics for network id=3D206 on -1 > 2013-08-07 16:27:34,306 DEBUG [cloud.network.NetworkManagerImpl] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Juniper= SRX 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Netscal= er 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-Exe= cutor-2:job-57 =3D [ 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking CiscoNe= xus1000vVSM 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking CiscoVN= MC 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking NiciraN= vp 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Checking if Ni= ciraNvpElement can handle service Connectivity on network new network > 2013-08-07 16:27:34,307 DEBUG [cloud.network.NetworkManagerImpl] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Virtual= Router 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-Exe= cutor-2:job-57 =3D [ 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Securit= yGroupProvider 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking VpcVirt= ualRouter 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking Interna= lLbVm 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking BareMet= alDhcp 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking BareMet= alPxe 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Asking BareMet= alUserdata 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-E= xecutor-2:job-57 =3D [ 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-E= xecutor-2:job-57 =3D [ 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Depl= oy avoids pods: null, clusters: null, hosts: [3] > 2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Depl= oymentPlanner allocation algorithm: com.cloud.deploy.UserConcentratedPodPla= nner_EnhancerByCloudStack_1f122a17@5b12bba0 > 2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Tryi= ng to allocate a host and storage pools from dc:1, pod:1,cluster:1, request= ed cpu: 500, requested ram: 536870912 > 2013-08-07 16:27:34,322 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Is R= OOT volume READY (pool already allocated)?: No > 2013-08-07 16:27:34,323 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Depl= oymentPlan has host_id specified, choosing this host and making no checks o= n this host: 3 > 2013-08-07 16:27:34,325 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Cann= not deploy to specified host, returning. > 2013-08-07 16:27:34,365 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state tra= nsitted 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-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Hosts's actu= al total CPU: 9576 and CPU after applying overprovisioning: 9576 > 2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Hosts's actu= al total RAM: 8243073024 and RAM after applying overprovisioning: 824307302= 4 > 2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 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: f= alse,moveToReserveredfalse > 2013-08-07 16:27:34,373 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) release mem = from host: 3, old used: 5502926848,reserved: 1073741824, total: 8243073024;= new used: 4966055936,reserved:1073741824; movedfromreserved: false,moveToR= eserveredfalse > 2013-08-07 16:27:34,421 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state tra= nsitted from :Stopped to Starting with event: StartRequestedvm's original h= ost id: null new host id: null host id before state transition: null > 2013-08-07 16:27:34,421 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Successfully= transitioned to start state for VM[User|vnew-2k8-402] reservation id =3D e= f1819ff-9f8e-46f9-b132-ef4cf53b5159 > 2013-08-07 16:27:34,426 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Trying to de= ploy VM, vm has dcId: 1 and podId: 1 > 2013-08-07 16:27:34,426 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Deploy avoid= s pods: null, clusters: null, hosts: [3] > 2013-08-07 16:27:34,439 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Depl= oy avoids pods: null, clusters: null, hosts: [3] > 2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Depl= oymentPlanner allocation algorithm: com.cloud.deploy.UserConcentratedPodPla= nner_EnhancerByCloudStack_1f122a17@5b12bba0 > 2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Tryi= ng to allocate a host and storage pools from dc:1, pod:1,cluster:null, requ= ested cpu: 500, requested ram: 536870912 > 2013-08-07 16:27:34,441 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Is R= OOT volume READY (pool already allocated)?: No > 2013-08-07 16:27:34,441 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executo= r-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Searching resource= s only under specified Pod: 1 > 2013-08-07 16:27:34,441 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executo= r-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Listing clusters i= n 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Chec= king resources in Cluster: 1 under Pod: 1 > 2013-08-07 16:27:34,451 DEBUG [allocator.impl.FirstFitAllocator] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) Looking for hosts in dc: 1 pod:1 cluster:1 > 2013-08-07 16:27:34,456 DEBUG [allocator.impl.FirstFitAllocator] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-3-= Routing]] > 2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) Found 1 hosts for allocation after prioritization: [Host[-3-Rout= ing]] > 2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) Looking for speed=3D500Mhz, Ram=3D512 > 2013-08-07 16:27:34,459 DEBUG [allocator.impl.FirstFitAllocator] (Job-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) 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-Exe= cutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ] FirstFitRouting= Allocator) Host Allocator returning 0 suitable hosts > 2013-08-07 16:27:34,459 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) No s= uitable hosts found > 2013-08-07 16:27:34,459 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) No s= uitable hosts found under this Cluster: 1 > 2013-08-07 16:27:34,464 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl= ] (Job-Executor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Coul= d not find suitable Deployment Destination for this VM under any clusters, = returning. > 2013-08-07 16:27:34,464 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executo= r-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Searching resource= s only under specified Pod: 1 > 2013-08-07 16:27:34,464 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executo= r-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Listing clusters i= n 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-Executo= r-2:job-57 =3D [ 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-Executo= r-2:job-57 =3D [ 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-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state tra= nsitted 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Destroying vm VM[Use= r|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-E= xecutor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) VM state tra= nsitted from :Stopped to Error with event: OperationFailedToErrorvm's origi= nal 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 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) alertType:: 8 // data= CenterId:: 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-5= 7 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) com.cloud.exception.Insuffi= cientServerCapacityException: Unable to create a deployment for VM[User|vne= w-2k8-402]Scope=3Dinterface com.cloud.dc.DataCenter; id=3D1 > 2013-08-07 16:27:34,584 INFO [user.vm.DeployVMCmd] (Job-Executor-2:job-5= 7 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Unable to create a deployme= nt for VM[User|vnew-2k8-402] > com.cloud.exception.InsufficientServerCapacityException: Unable to create= a deployment for VM[User|vnew-2k8-402]Scope=3Dinterface com.cloud.dc.DataC= enter; id=3D1 > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMac= hineManagerImpl.java:888) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineMan= agerImpl.java:624) > at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerI= mpl.deployVirtualMachine(VMEntityManagerImpl.java:237) > at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEn= tityImpl.deploy(VirtualMachineEntityImpl.java:209) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:3408) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:2968) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManag= erImpl.java:2954) > at com.cloud.utils.component.ComponentInstantiationPostProcessor$= InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:12= 5) > 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(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:603) > at java.lang.Thread.run(Thread.java:636) > 2013-08-07 16:27:34,586 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Exec= utor-2:job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ]) Complete async = job-57 =3D [ 3108142a-644b-4466-9ed0-b8d5d22f3fcc ], jobStatus: 2, resultCo= de: 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 matchi= ng 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/2f= 032a82-d189-4587-9a93-41ee1f864641 > /mnt/9fb7c84b-bfff-3ca2-9fc0-f50181c6b1f0/2f032a82-d189-4587-9a93-41ee1f8= 64641 > [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 i= nitially 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 a= ll user vms went to stopped state.=20 > 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 administrato= rs For more information on JIRA, see: http://www.atlassian.com/software/jira