[ 
https://issues.apache.org/jira/browse/CLOUDSTACK-4145?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Animesh Chaturvedi updated CLOUDSTACK-4145:
-------------------------------------------

    Assignee: Rajesh Battala
    
> [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
>            Assignee: Rajesh Battala
>            Priority: Blocker
>             Fix For: 4.2.0
>
>         Attachments: CS-4145.zip
>
>
> 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

Reply via email to