[ https://issues.apache.org/jira/browse/CLOUDSTACK-2985?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13729398#comment-13729398 ]
prashant kumar mishra commented on CLOUDSTACK-2985: --------------------------------------------------- scaling up cpu is failing because live migration failed with "MigrationCommand failed due to Exception: java.lang.RuntimeException Message: Operation timed out." my observation ------------------------- 1-stoped vm migrated successfully when i powered it on and enough cpu resource was not there on current host 2-manully live migration was successful Logs ---------- ---------- Migration initiation 2013-08-05 21:53:13,021 DEBUG [agent.transport.Request] (Job-Executor-15:job-230 = [ c27088de-0339-4721-9e2d-4fb81376f43a ]) Seq 6-1354432530: Sending { Cmd , MgmtId: 6703101771911, via: 6, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":24,"name":"i-2-24-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"d5c100c9cd39af14","params":{"rootDiskController":"ide","nicAdapter":"E1000","nestedVirtualizationFlag":"false"},"uuid":"8afa1f58-e903-4582-9ec8-02795d941bf2","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"4862a719-380f-4d7f-b573-10de3a110e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"391391f1-4ef9-373e-bf7e-906db6d39a39","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/vmw_primary","port":2049}},"name":"ROOT-24","size":2147483648,"path":"ROOT-24-24","volumeId":24,"vmName":"i-2-24-VM","accountId":2,"format":"OVA","id":24,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"df5bf23c-692c-4e2a-9a2f-fa4c7528a486","ip":"10.1.1.118","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:11:68:00:15","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1118","isolationUri":"vlan://1118","isSecurityGroupEnabled":false}]},"wait":0}}] } 2013-08-05 21:53:13,023 DEBUG [agent.transport.Request] (Job-Executor-15:job-230 = [ c27088de-0339-4721-9e2d-4fb81376f43a ]) Seq 6-1354432530: Executing: { Cmd , MgmtId: 6703101771911, via: 6, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":24,"name":"i-2-24-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"d5c100c9cd39af14","params":{"rootDiskController":"ide","nicAdapter":"E1000","nestedVirtualizationFlag":"false"},"uuid":"8afa1f58-e903-4582-9ec8-02795d941bf2","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"4862a719-380f-4d7f-b573-10de3a110e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"391391f1-4ef9-373e-bf7e-906db6d39a39","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/vmw_primary","port":2049}},"name":"ROOT-24","size":2147483648,"path":"ROOT-24-24","volumeId":24,"vmName":"i-2-24-VM","accountId":2,"format":"OVA","id":24,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"df5bf23c-692c-4e2a-9a2f-fa4c7528a486","ip":"10.1.1.118","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:11:68:00:15","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1118","isolationUri":"vlan://1118","isSecurityGroupEnabled":false}]},"wait":0}}] } 2013-08-05 21:53:13,025 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===START=== 10.252.192.53 -- GET command=queryAsyncJobResult&jobId=c27088de-0339-4721-9e2d-4fb81376f43a&response=json&sessionkey=FOkqF80I%2Fd5pGCEqRC1akZdN41E%3D&_=1375700312413 2013-08-05 21:53:13,028 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-16:null) Seq 6-1354432530: Executing request 2013-08-05 21:53:13,038 INFO [vmware.resource.VmwareResource] (DirectAgent-16:10.147.40.9) Executing resource PrepareForMigrationCommand: {"vm":{"id":24,"name":"i-2-24-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"d5c100c9cd39af14","params":{"rootDiskController":"ide","nicAdapter":"E1000","nestedVirtualizationFlag":"false"},"uuid":"8afa1f58-e903-4582-9ec8-02795d941bf2","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"4862a719-380f-4d7f-b573-10de3a110e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"391391f1-4ef9-373e-bf7e-906db6d39a39","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/vmw_primary","port":2049}},"name":"ROOT-24","size":2147483648,"path":"ROOT-24-24","volumeId":24,"vmName":"i-2-24-VM","accountId":2,"format":"OVA","id":24,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"df5bf23c-692c-4e2a-9a2f-fa4c7528a486","ip":"10.1.1.118","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:11:68:00:15","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1118","isolationUri":"vlan://1118","isSecurityGroupEnabled":false}]},"wait":0} migration failed -------------------------- 2013-08-05 21:55:24,706 WARN [vmware.resource.VmwareResource] (DirectAgent-32:10.147.40.18) MigrationCommand failed due to Exception: java.lang.RuntimeException Message: Operation timed out. java.lang.RuntimeException: Operation timed out. at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:290) at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.migrate(VirtualMachineMO.java:331) at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:3796) at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:462) at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) 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:679) scaling up failed ------------------------- 2013-08-05 21:55:32,049 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 6-1354432538: Received: { Ans: , MgmtId: 6703101771911, via: 6, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-08-05 21:55:32,994 ERROR [vmware.resource.VmwareResource] (DirectAgent-35:10.147.40.18) Unexpected exception: java.lang.RuntimeException: The hot-plug operation failed. at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:290) at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:835) at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2555) at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:564) at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) 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:679) 2013-08-05 21:55:32,996 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-35:null) Seq 1-113 > Scaling up cpu is not triggering live migration > ----------------------------------------------- > > Key: CLOUDSTACK-2985 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2985 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Management Server > Affects Versions: 4.2.0 > Environment: VMware esxi 5.1 > Reporter: prashant kumar mishra > Assignee: Nitin Mehta > Priority: Critical > Fix For: 4.2.0 > > Attachments: DB_Logs.rar > > > Steps to reproduce > ----------------------------- > 1-have a vmware cluster with one host > 2-exhaust cpu capacity of cluster by deploying vms > 3-Add one more host to cluster > 4-try to scale up a vm from SO ( RAM :512,CPU:500 MHz) to SO (RAM:512 to > CPU:1000) > Expected > ---------------- > Since there is no cpu resource left on host , vm should scale up after live > migration > Actual > --------- > VM scale up failed due to "The available CPU resources in the parent resource > pool are insufficient for the operation" > Snippet of Log > ------------------------ > 2013-06-13 12:42:04,802 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) RAM STATS after allocation: for host: 1, old used: > 5502926848, old reserved: 0, total: 17169539072; new used: 6039797760, > reserved: 0; requested mem: 536870912,alloc_from_last:false > 2013-06-13 12:42:04,813 DEBUG [agent.transport.Request] > (Job-Executor-19:job-288) Seq 1-974783027: Sending { Cmd , MgmtId: > 7635042566263, via: 1, Ver: v1, Flags: 100111, > [{"ScaleVmCommand":{"vm":{"id":1,"name":"i-2-45-VM","cpus":1,"speed":1000,"minRam":512,"maxRam":512,"rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false},"vmName":"i-2-45-VM","cpus":1,"speed":1000,"minRam":512,"maxRam":512,"wait":0}}] > } > 2013-06-13 12:42:04,815 DEBUG [agent.transport.Request] > (Job-Executor-19:job-288) Seq 1-974783027: Executing: { Cmd , MgmtId: > 7635042566263, via: 1, Ver: v1, Flags: 100111, > [{"ScaleVmCommand":{"vm":{"id":1,"name":"i-2-45-VM","cpus":1,"speed":1000,"minRam":512,"maxRam":512,"rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false},"vmName":"i-2-45-VM","cpus":1,"speed":1000,"minRam":512,"maxRam":512,"wait":0}}] > } > 2013-06-13 12:42:04,815 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-213:null) Seq 1-974783027: Executing request > 2013-06-13 12:42:04,816 DEBUG [vmware.mo.HostMO] > (DirectAgent-213:10.147.40.7) find VM i-2-45-VM on host > 2013-06-13 12:42:04,816 DEBUG [vmware.mo.HostMO] > (DirectAgent-213:10.147.40.7) load VM cache on host > 2013-06-13 12:42:06,191 ERROR [vmware.resource.VmwareResource] > (DirectAgent-213:10.147.40.7) Unexpected exception: > java.lang.RuntimeException: The available CPU resources in the parent > resource pool are insufficient for the operation. > at > com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:291) > at > com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:832) > at > com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2331) > at > com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:559) > at > com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) > 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) > 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:679) > 2013-06-13 12:42:06,193 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-213:null) Seq 1-974783027: Response Received: > 2013-06-13 12:42:06,194 DEBUG [agent.transport.Request] > (DirectAgent-213:null) Seq 1-974783027: Processing: { Ans: , MgmtId: > 7635042566263, via: 1, Ver: v1, Flags: 110, > [{"ScaleVmAnswer":{"result":false,"details":"Unable to execute ScaleVmCommand > due to java.lang.RuntimeException: The available CPU resources in the parent > resource pool are insufficient for the operation.","wait":0}}] } > 2013-06-13 12:42:06,194 DEBUG [agent.transport.Request] > (Job-Executor-19:job-288) Seq 1-974783027: Received: { Ans: , MgmtId: > 7635042566263, via: 1, Ver: v1, Flags: 110, { ScaleVmAnswer } } > 2013-06-13 12:42:06,194 ERROR [cloud.vm.VirtualMachineManagerImpl] > (Job-Executor-19:job-288) Unable to scale vm due to Unable to execute > ScaleVmCommand due to java.lang.RuntimeException: The available CPU resources > in the parent resource pool are insufficient for the operation. > 2013-06-13 12:42:06,199 DEBUG [agent.manager.AgentAttache] > (DirectAgent-213:null) Seq 1-974783027: No more commands found > 2013-06-13 12:42:06,209 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) Hosts's actual total CPU: 9572 and CPU after > applying overprovisioning: 9572 > 2013-06-13 12:42:06,209 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) Hosts's actual total RAM: 17169539072 and RAM after > applying overprovisioning: 17169539072 > 2013-06-13 12:42:06,209 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) release cpu from host: 1, old used: 8200,reserved: > 0, actual total: 9572, total with overprovisioning: 9572; new used: > 7200,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-06-13 12:42:06,209 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) release mem from host: 1, old used: > 6039797760,reserved: 0, total: 17169539072; new used: 5502926848,reserved:0; > movedfromreserved: false,moveToReserveredfalse > 2013-06-13 12:42:06,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) Hosts's actual total CPU: 9572 and CPU after > applying overprovisioning: 9572 > 2013-06-13 12:42:06,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) We are allocating VM, increasing the used capacity > of this host:1 > 2013-06-13 12:42:06,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) Current Used CPU: 7200 , Free CPU:2372 ,Requested > CPU: 500 > 2013-06-13 12:42:06,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) Current Used RAM: 5502926848 , Free RAM:11666612224 > ,Requested RAM: 536870912 > 2013-06-13 12:42:06,233 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) CPU STATS after allocation: for host: 1, old used: > 7200, old reserved: 0, actual total: 9572, total with overprovisioning: 9572; > new used:7700, reserved:0; requested cpu:500,alloc_from_last:false > 2013-06-13 12:42:06,234 DEBUG [cloud.capacity.CapacityManagerImpl] > (Job-Executor-19:job-288) RAM STATS after allocation: for host: 1, old used: > 5502926848, old reserved: 0, total: 17169539072; new used: 6039797760, > reserved: 0; requested mem: 536870912,alloc_from_last:false > 2013-06-13 12:42:06,264 ERROR [cloud.async.AsyncJobManagerImpl] > (Job-Executor-19:job-288) Unexpected exception while executing > org.apache.cloudstack.api.command.user.vm.ScaleVMCmd > com.cloud.utils.exception.CloudRuntimeException: Unable to scale vm due to > Unable to execute ScaleVmCommand due to java.lang.RuntimeException: The > available CPU resources in the parent resource pool are insufficient for the > operation. > at > com.cloud.vm.VirtualMachineManagerImpl.reConfigureVm(VirtualMachineManagerImpl.java:3250) > at > com.cloud.vm.UserVmManagerImpl.upgradeVirtualMachine(UserVmManagerImpl.java:1227) > at > com.cloud.vm.UserVmManagerImpl.upgradeVirtualMachine(UserVmManagerImpl.java:1106) > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at > org.apache.cloudstack.api.command.user.vm.ScaleVMCmd.execute(ScaleVMCmd.java:92) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437) > 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:679) > 2013-06-13 12:42:06,266 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-19:job-288) Complete async job-288, jobStatus: 2, resultCode: > 530, result: Error Code: 530 Error text: Unable to scale vm due to Unable to > execute ScaleVmCommand due to java.lang.RuntimeException: The available CPU > resources in the parent resource pool are insufficient for the operation. -- 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