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 D75081049C for ; Fri, 7 Jun 2013 19:52:21 +0000 (UTC) Received: (qmail 35145 invoked by uid 500); 7 Jun 2013 19:52:21 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 35105 invoked by uid 500); 7 Jun 2013 19:52:21 -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 35039 invoked by uid 500); 7 Jun 2013 19:52:21 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 35007 invoked by uid 99); 7 Jun 2013 19:52:21 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 07 Jun 2013 19:52:21 +0000 Date: Fri, 7 Jun 2013 19:52:21 +0000 (UTC) From: "angeline shen (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-2887) PVLAN - vmware dvswitch - destroy VM fail with VM stuck in 'Stopping' state MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-2887?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] angeline shen updated CLOUDSTACK-2887: -------------------------------------- Priority: Blocker (was: Critical) > PVLAN - vmware dvswitch - destroy VM fail with VM stuck in 'Stopping' state > ---------------------------------------------------------------------------- > > Key: CLOUDSTACK-2887 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2887 > 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: MS ASF 2.0 build CloudStack-non-OSS-MASTER-452-rhel6.3.tar.gz > vcenter ESXi 5.0 hosts > Reporter: angeline shen > Assignee: Venkata Siva Vijayendra Bhamidipati > Priority: Blocker > Fix For: 4.2.0 > > Attachments: management-server.log.gz, management-server.log.gz, Screenshot-CloudStack - Mozilla Firefox-7.png > > > 1. zone with two PVLAN networks > 2. deploy VMs in both PVLANs. > Confirm VMs in same PVLAN cannot connect to each other. > confirm VMs in 1 PVLAN can reach VMs in other PVLAN. VMs can reach outside world > 3. Destroy VMs in both PVLANs. > Result: VMS remain in Stopping state. > 2013-06-06 15:46:57,467 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START=== 10.216.133.70 -- GET command=destroyVirtualMachine&id=c27541d9-f4d2-40fc-8fab-3edfadc4067e&response=json&sessionkey=RV1iRzQ3pg636vVZIwdb > rJlAJXU%3D&_=1370559071830 > 2013-06-06 15:46:57,575 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-10:null) submit async job-34, details: AsyncJobVO {id:34, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 12, c > md: org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdOriginator: null, cmdInfo: {"response":"json","id":"c27541d9-f4d2-40fc-8fab-3edfadc4067e","sessionkey":"RV1iRzQ3pg636vVZIwdbrJlAJXU\u003d","ctxUserId":"2","httpmeth > od":"GET","_":"1370559071830","ctxAccountId":"2","ctxStartEventId":"132"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 206915885077197, completeMsid > : null, lastUpdated: null, lastPolled: null, created: null} > 2013-06-06 15:46:57,577 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-34:job-34) Executing org.apache.cloudstack.api.command.user.vm.DestroyVMCmd for job-34 > 2013-06-06 15:46:57,578 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END=== 10.216.133.70 -- GET command=destroyVirtualMachine&id=c27541d9-f4d2-40fc-8fab-3edfadc4067e&response=json&sessionkey=RV1iRzQ3pg636vVZIwdbrJlAJXU%3D&_=1370559071830 > 2013-06-06 15:46:57,630 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-34:job-34) Destroying vm VM[User|vm1612V61] > 2013-06-06 15:46:57,667 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-34:job-34) VM state transitted from :Running to Stopping with event: StopRequestedvm's original host id: 1 new host id: 2 host id before state transition: 2 > 2013-06-06 15:46:57,702 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-34:job-34) Unexpected exception while executing org.apache.cloudstack.api.command.user.vm.DestroyVMCmd > java.lang.ClassCastException: com.cloud.vm.VMInstanceVO$$EnhancerByCGLIB$$a77eface cannot be cast to com.cloud.vm.UserVmVO > at com.cloud.vm.UserVmManagerImpl.prepareStop(UserVmManagerImpl.java:4712) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1168) > at com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1285) > at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:265) > at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:225) > at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:3385) > at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:1898) > at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at org.apache.cloudstack.api.command.user.vm.DestroyVMCmd.execute(DestroyVMCmd.java:100) > 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-06 15:46:57,703 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-34:job-34) Complete async job-34, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: com.cloud.vm.VMInstanceVO$$EnhancerByCGLIB$$a77eface cannot be cast to com.cloud.vm.UserVmVO > 2013-06-06 15:47:00,621 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===START=== 10.216.133.70 -- GET command=queryAsyncJobResult&jobId=f8a46980-8409-4ead-a209-a799e202f959&response=json&sessionkey=RV1iRzQ3pg636vVZIwdbrJlAJXU%3D&_=1370559074987 > 2013-06-06 15:47:00,632 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-20:null) Async job-34 completed > 2013-06-06 15:47:00,636 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===END=== 10.216.133.70 -- GET command=queryAsyncJobResult&jobId=f8a46980-8409-4ead-a209-a799e202f959&response=json&sessionkey=RV1iRzQ3pg636vVZIwdbrJlAJXU%3D&_=1370559074987 > 2013-06-06 15:47:01,599 DEBUG [cloud.server.StatsCollec > 4. In DB, patch VM entries to Stopped state, then try Destroy VM. > VM remain in 'Expunging' state > [agent.manager.DirectAgentAttache] (DirectAgent-452:null) Seq 2-224136613: Response Received: > 2013-06-06 16:43:46,663 DEBUG [agent.transport.Request] (DirectAgent-452:null) Seq 2-224136613: Processing: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, [{"Answer":{"result":false,"details":"Expunge failed in vSphere. vm: i-2-3-VM","wait":0}}] } > 2013-06-06 16:43:46,663 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136613: Received: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, { Answer } } > 2013-06-06 16:43:46,663 WARN [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Failed to expunge vm due to: Expunge failed in vSphere. vm: i-2-3-VM > 2013-06-06 16:43:46,663 INFO [cloud.vm.UserVmManagerImpl] (UserVm-Scavenger-1:null) Did not expunge VM[User|z1vmware1611V7] > 2013-06-06 16:43:46,663 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Stopped called on VM[User|z1vmware1611V72] but the state is Expunging > 2013-06-06 16:43:46,695 DEBUG [cloud.capacity.CapacityManagerImpl] (UserVm-Scavenger-1:null) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: 2 new host id: 2 host id before state transition: 2 > 2013-06-06 16:43:46,696 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Destroying vm VM[User|z1vmware1611V72] > 2013-06-06 16:43:46,696 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Cleaning up NICS > 2013-06-06 16:43:46,696 DEBUG [cloud.network.NetworkManagerImpl] (UserVm-Scavenger-1:null) Cleaning network for vm: 6 > 2013-06-06 16:43:46,698 DEBUG [cloud.storage.VolumeManagerImpl] (UserVm-Scavenger-1:null) Cleaning storage for vm: 6 > 2013-06-06 16:43:46,700 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136614: Sending { Cmd , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 100011, [{"UnregisterVMCommand":{"vmName":"i-2-6-VM","wait":0}}] } > 2013-06-06 16:43:46,700 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136614: Executing: { Cmd , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 100011, [{"UnregisterVMCommand":{"vmName":"i-2-6-VM","wait":0}}] } > 2013-06-06 16:43:46,701 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-196:null) Seq 2-224136614: Executing request > 2013-06-06 16:43:46,701 INFO [vmware.resource.VmwareResource] (DirectAgent-196:10.223.81.40) Executing resource UnregisterVMCommand: {"vmName":"i-2-6-VM","wait":0} > 2013-06-06 16:43:46,701 DEBUG [vmware.mo.HostMO] (DirectAgent-196:10.223.81.40) find VM i-2-6-VM on host > 2013-06-06 16:43:46,701 DEBUG [vmware.mo.HostMO] (DirectAgent-196:10.223.81.40) load VM cache on host > 2013-06-06 16:43:46,735 WARN [vmware.resource.VmwareResource] (DirectAgent-196:10.223.81.40) We are not able to unregister VM Exception: com.vmware.vim25.InvalidPowerState > message: [] > 2013-06-06 16:43:46,735 WARN [vmware.resource.VmwareResource] (DirectAgent-196:10.223.81.40) Expunge failed in vSphere. vm: i-2-6-VM > 2013-06-06 16:43:46,735 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-196:null) Seq 2-224136614: Response Received: > 2013-06-06 16:43:46,735 DEBUG [agent.transport.Request] (DirectAgent-196:null) Seq 2-224136614: Processing: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, [{"Answer":{"result":false,"details":"Expunge failed in vSphere. vm: i-2-6-VM","wait":0}}] } > 2013-06-06 16:43:46,735 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136614: Received: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, { Answer } } > 2013-06-06 16:43:46,735 WARN [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Failed to expunge vm due to: Expunge failed in vSphere. vm: i-2-6-VM > 2013-06-06 16:43:46,735 INFO [cloud.vm.UserVmManagerImpl] (UserVm-Scavenger-1:null) Did not expunge VM[User|z1vmware1611V72] > 2013-06-06 16:43:46,735 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Stopped called on VM[User|z1vmware1611V73] but the state is Expunging > 2013-06-06 16:43:46,771 DEBUG [cloud.capacity.CapacityManagerImpl] (UserVm-Scavenger-1:null) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: 1 new host id: 1 host id before stat: > 2013-06-06 16:43:46,799 WARN [vmware.resource.VmwareResource] (DirectAgent-429:10.223.81.41) Expunge failed in vSphere. vm: i-2-7-VM > 2013-06-06 16:43:46,799 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-429:null) Seq 1-1694436621: Response Received: > 2013-06-06 16:43:46,799 DEBUG [agent.transport.Request] (DirectAgent-429:null) Seq 1-1694436621: Processing: { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, [{"Answer":{"result":false,"details":"Expunge failed in vSphere. vm: i-2-7-VM","wait":0}}] } > 2013-06-06 16:43:46,799 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 1-1694436621: Received: { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, { Answer } } > 2013-06-06 16:43:46,799 WARN [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Failed to expunge vm due to: Expunge failed in vSphere. vm: i-2-7-VM > 2013-06-06 16:43:46,800 INFO [cloud.vm.UserVmManagerImpl] (UserVm-Scavenger-1:null) Did not expunge VM[User|z1vmware1611V73] > 2013-06-06 16:43:46,800 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Stopped called on VM[User|vm1612V61] but the state is Expunging > 2013-06-06 16:43:46,838 DEBUG [cloud.capacity.CapacityManagerImpl] (UserVm-Scavenger-1:null) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: 1 new host id: 2 host id before state transition: 2 > 2013-06-06 16:43:46,838 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Destroying vm VM[User|vm1612V61] > 2013-06-06 16:43:46,838 DEBUG [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Cleaning up NICS > 2013-06-06 16:43:46,838 DEBUG [cloud.network.NetworkManagerImpl] (UserVm-Scavenger-1:null) Cleaning network for vm: 12 > 2013-06-06 16:43:46,839 DEBUG [cloud.storage.VolumeManagerImpl] (UserVm-Scavenger-1:null) Cleaning storage for vm: 12 > 2013-06-06 16:43:46,842 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136615: Sending { Cmd , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 100011, [{"UnregisterVMCommand":{"vmName":"i-2-12-VM","wait":0}}] } > 2013-06-06 16:43:46,842 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136615: Executing: { Cmd , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 100011, [{"UnregisterVMCommand":{"vmName":"i-2-12-VM","wait":0}}] } > 2013-06-06 16:43:46,842 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-130:null) Seq 2-224136615: Executing request > 2013-06-06 16:43:46,843 INFO [vmware.resource.VmwareResource] (DirectAgent-130:10.223.81.40) Executing resource UnregisterVMCommand: {"vmName":"i-2-12-VM","wait":0} > 2013-06-06 16:43:46,843 DEBUG [vmware.mo.HostMO] (DirectAgent-130:10.223.81.40) find VM i-2-12-VM on host > 2013-06-06 16:43:46,843 DEBUG [vmware.mo.HostMO] (DirectAgent-130:10.223.81.40) load VM cache on host > 2013-06-06 16:43:46,858 WARN [vmware.resource.VmwareResource] (DirectAgent-130:10.223.81.40) We are not able to unregister VM Exception: com.vmware.vim25.InvalidPowerState > message: [] > 2013-06-06 16:43:46,858 WARN [vmware.resource.VmwareResource] (DirectAgent-130:10.223.81.40) Expunge failed in vSphere. vm: i-2-12-VM > 2013-06-06 16:43:46,858 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-130:null) Seq 2-224136615: Response Received: > 2013-06-06 16:43:46,859 DEBUG [agent.transport.Request] (DirectAgent-130:null) Seq 2-224136615: Processing: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, [{"Answer":{"result":false,"details":"Expunge failed in vSphere. vm: i-2-12-VM","wait":0}}] } > 2013-06-06 16:43:46,859 DEBUG [agent.transport.Request] (UserVm-Scavenger-1:null) Seq 2-224136615: Received: { Ans: , MgmtId: 206915885077197, via: 2, Ver: v1, Flags: 10, { Answer } } > 2013-06-06 16:43:46,859 WARN [cloud.vm.VirtualMachineManagerImpl] (UserVm-Scavenger-1:null) Failed to expunge vm due to: Expunge failed in vSphere. vm: i-2-12-VM > 2013-06-06 16:43:46,859 INFO [cloud.vm.UserVmManagerImpl] (UserVm-Scavenger-1:null) Did not expunge VM[User|vm1612V61] > 2013-06-06 16:43:47,371 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START=== 10.216.133.70 -- GET command=listDomains&id=ec9a7ec4-ce3c-11e2-add9-f923bf56723a&listAll=true&response=json&sessionkey=RV1iRzQ3pg636vVZIwdbrJlAJXU%3D&_=1370562481753 -- 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