[ https://issues.apache.org/jira/browse/CLOUDSTACK-5360?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rajesh Battala updated CLOUDSTACK-5360: --------------------------------------- Labels: (was: hyper-V,) > [Hyper-V] Failed to stop/destroy system vms > ------------------------------------------- > > Key: CLOUDSTACK-5360 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5360 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Hypervisor Controller, Management Server > Affects Versions: 4.3.0 > Environment: 4.3 > Hypervisor: Hyperv > Storage: CIFS for secondary storage and Local storage for primary > Reporter: Sanjeev N > Priority: Critical > Fix For: 4.3.0 > > Attachments: management-server.rar > > > [Hyper-V] Failed to stop/destroy system vms > Steps to Reproduce: > ================ > 1.Bring up CS in advanced zone with hyperv using CIFS for secondary and Local > storage for primary > 2.Wait for the SSVM and CPVM to come up in running state > 3.Disable the zone > 4.Try to destroy SSVM and CPVM > Expected Result: > ============= > System vm should be destroyed successfully. > Actual Result: > ============ > Failed to stop system vms. They remained in running state. > Log snippet from the management server log as follows: > 2013-12-04 05:38:10,648 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (catalina-exec-17:ctx-58df498b ctx-803fc411) submit async job-45, details: > AsyncJobVO {id:45, userId: 2, accountId: 2, instanceType: SystemVm, > instanceId: 2, cmd: > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: > {"id":"69f6f9f1-098a-45bb-a57e-40770577358f","response":"json","sessionkey":"6gEqK4AUWb7klI/aOH9lLsIqrVc\u003d","cmdEventType":"PROXY.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1386133822298","ctxAccountId":"2","ctxStartEventId":"217"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: > null, initMsid: 7332683579487, completeMsid: null, lastUpdated: null, > lastPolled: null, created: null} > 2013-12-04 05:38:10,649 DEBUG [c.c.a.ApiServlet] > (catalina-exec-17:ctx-58df498b ctx-803fc411) ===END=== 10.146.0.134 -- GET > command=destroySystemVm&id=69f6f9f1-098a-45bb-a57e-40770577358f&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133822298 > 2013-12-04 05:38:10,651 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (Job-Executor-30:ctx-d6a82988) Add job-45 into job monitoring > 2013-12-04 05:38:10,651 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Job-Executor-30:ctx-d6a82988) Executing AsyncJobVO {id:45, userId: 2, > accountId: 2, instanceType: SystemVm, instanceId: 2, cmd: > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: > {"id":"69f6f9f1-098a-45bb-a57e-40770577358f","response":"json","sessionkey":"6gEqK4AUWb7klI/aOH9lLsIqrVc\u003d","cmdEventType":"PROXY.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1386133822298","ctxAccountId":"2","ctxStartEventId":"217"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: > null, initMsid: 7332683579487, completeMsid: null, lastUpdated: null, > lastPolled: null, created: null} > 2013-12-04 05:38:10,703 DEBUG [c.c.c.CapacityManagerImpl] > (Job-Executor-30:ctx-d6a82988 ctx-803fc411) VM state transitted from :Running > to Stopping with event: StopRequestedvm's original host id: 1 new host id: 1 > host id before state transition: 1 > 2013-12-04 05:38:10,707 DEBUG [c.c.a.t.Request] (Job-Executor-30:ctx-d6a82988 > ctx-803fc411) Seq 1-1034949124: Sending { Cmd , MgmtId: 7332683579487, via: > 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","wait":0}}] > } > 2013-12-04 05:38:10,707 DEBUG [c.c.a.t.Request] (Job-Executor-30:ctx-d6a82988 > ctx-803fc411) Seq 1-1034949124: Executing: { Cmd , MgmtId: 7332683579487, > via: 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","wait":0}}] > } > 2013-12-04 05:38:10,707 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-367:ctx-948bcdad) Seq 1-1034949124: Executing request > 2013-12-04 05:38:10,708 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-367:ctx-948bcdad) POST request > tohttp://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > with > contents{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","contextMap":{},"wait":0} > 2013-12-04 05:38:10,708 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-367:ctx-948bcdad) Sending cmd to > http://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > cmd > data:{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","contextMap":{},"wait":0} > 2013-12-04 05:38:10,739 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-15:null) SeqA 2-37267: Processing Seq 2-37267: { Cmd , > MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-12-04 05:38:10,745 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-15:null) SeqA 2-37267: Sending Seq 2-37267: { Ans: , > MgmtId: 7332683579487, via: 2, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-12-04 05:38:11,792 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-13:null) Ping from 3 > 2013-12-04 05:38:12,295 DEBUG [c.c.a.ApiServlet] > (catalina-exec-23:ctx-f5444059) ===START=== 10.146.0.134 -- GET > command=listZones&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&id=c86fcc9b-7ffe-4131-8345-fb19e170b50c&_=1386133824060 > 2013-12-04 05:38:12,313 DEBUG [c.c.a.ApiServlet] > (catalina-exec-23:ctx-f5444059 ctx-b670db7f) ===END=== 10.146.0.134 -- GET > command=listZones&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&id=c86fcc9b-7ffe-4131-8345-fb19e170b50c&_=1386133824060 > 2013-12-04 05:38:12,325 DEBUG [c.c.a.ApiServlet] > (catalina-exec-12:ctx-97e8ec33) ===START=== 10.146.0.134 -- GET > command=listSystemVms&id=b317147b-0114-477f-8902-18dfb50b4258&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133824086 > 2013-12-04 05:38:12,420 DEBUG [c.c.a.ApiServlet] > (catalina-exec-12:ctx-97e8ec33 ctx-52dfa8ad) ===END=== 10.146.0.134 -- GET > command=listSystemVms&id=b317147b-0114-477f-8902-18dfb50b4258&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133824086 > 2013-12-04 05:38:13,692 DEBUG [c.c.a.ApiServlet] > (catalina-exec-5:ctx-13162d15) ===START=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=df4fe69c-1fe4-4824-84ad-d51ac2fd6bd0&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133825454 > 2013-12-04 05:38:13,819 DEBUG [c.c.a.ApiServlet] > (catalina-exec-5:ctx-13162d15 ctx-e2281c4a) ===END=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=df4fe69c-1fe4-4824-84ad-d51ac2fd6bd0&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133825454 > 2013-12-04 05:38:14,689 DEBUG [c.c.a.ApiServlet] > (catalina-exec-22:ctx-360bacb7) ===START=== 10.146.0.134 -- GET > command=destroySystemVm&id=b317147b-0114-477f-8902-18dfb50b4258&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133826363 > 2013-12-04 05:38:14,718 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (catalina-exec-22:ctx-360bacb7 ctx-57f15ec1) submit async job-46, details: > AsyncJobVO {id:46, userId: 2, accountId: 2, instanceType: SystemVm, > instanceId: 4, cmd: > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: > {"response":"json","id":"b317147b-0114-477f-8902-18dfb50b4258","sessionkey":"6gEqK4AUWb7klI/aOH9lLsIqrVc\u003d","cmdEventType":"SSVM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1386133826363","ctxAccountId":"2","ctxStartEventId":"219"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: > null, initMsid: 7332683579487, completeMsid: null, lastUpdated: null, > lastPolled: null, created: null} > 2013-12-04 05:38:14,719 DEBUG [c.c.a.ApiServlet] > (catalina-exec-22:ctx-360bacb7 ctx-57f15ec1) ===END=== 10.146.0.134 -- GET > command=destroySystemVm&id=b317147b-0114-477f-8902-18dfb50b4258&response=json&sessionkey=6gEqK4AUWb7klI%2FaOH9lLsIqrVc%3D&_=1386133826363 > 2013-12-04 05:38:14,721 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (Job-Executor-31:ctx-8c475e02) Add job-46 into job monitoring > 2013-12-04 05:38:14,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Job-Executor-31:ctx-8c475e02) Executing AsyncJobVO {id:46, userId: 2, > accountId: 2, instanceType: SystemVm, instanceId: 4, cmd: > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: > {"response":"json","id":"b317147b-0114-477f-8902-18dfb50b4258","sessionkey":"6gEqK4AUWb7klI/aOH9lLsIqrVc\u003d","cmdEventType":"SSVM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1386133826363","ctxAccountId":"2","ctxStartEventId":"219"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: > null, initMsid: 7332683579487, completeMsid: null, lastUpdated: null, > lastPolled: null, created: null} > 2013-12-04 05:38:14,753 DEBUG [c.c.c.CapacityManagerImpl] > (Job-Executor-31:ctx-8c475e02 ctx-57f15ec1) VM state transitted from :Running > to Stopping with event: StopRequestedvm's original host id: 1 new host id: 1 > host id before state transition: 1 > 2013-12-04 05:38:14,756 DEBUG [c.c.a.t.Request] (Job-Executor-31:ctx-8c475e02 > ctx-57f15ec1) Seq 1-1034949125: Sending { Cmd , MgmtId: 7332683579487, via: > 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-4-VM","wait":0}}] > } > 2013-12-04 05:38:14,756 DEBUG [c.c.a.t.Request] (Job-Executor-31:ctx-8c475e02 > ctx-57f15ec1) Seq 1-1034949125: Executing: { Cmd , MgmtId: 7332683579487, > via: 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-4-VM","wait":0}}] > } > 2013-12-04 05:38:14,757 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-391:ctx-b73c2c15) Seq 1-1034949125: Executing request > 2013-12-04 05:38:14,757 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-391:ctx-b73c2c15) POST request > tohttp://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > with > contents{"isProxy":false,"executeInSequence":false,"vmName":"s-4-VM","contextMap":{},"wait":0} > 2013-12-04 05:38:14,757 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-391:ctx-b73c2c15) Sending cmd to > http://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > cmd > data:{"isProxy":false,"executeInSequence":false,"vmName":"s-4-VM","contextMap":{},"wait":0} > 2013-12-04 05:40:12,028 WARN [c.c.a.m.AgentManagerImpl] > (Job-Executor-30:ctx-d6a82988 ctx-803fc411) Unsupported Command: Unsupported > command issued:com.cloud.agent.api.StopCommand. Are you sure you got the > right type of server? > 2013-12-04 05:40:12,029 WARN [c.c.v.VirtualMachineManagerImpl] > (Job-Executor-30:ctx-d6a82988 ctx-803fc411) Unable to stop vm > VM[ConsoleProxy|v-2-VM] > 2013-12-04 05:40:12,037 DEBUG [c.c.c.CapacityManagerImpl] > (Job-Executor-30:ctx-d6a82988 ctx-803fc411) VM state transitted from > :Stopping to Running with event: OperationFailedvm's original host id: 1 new > host id: 1 host id before state transition: 1 > 2013-12-04 05:40:12,044 ERROR [c.c.a.ApiAsyncJobDispatcher] > (Job-Executor-30:ctx-d6a82988) Unexpected exception while executing > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd > com.cloud.utils.exception.CloudRuntimeException: Unable to stop > VM[ConsoleProxy|v-2-VM] > at > com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1406) > at > com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:450) > at > com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:439) > at > com.cloud.vm.VirtualMachineManagerImpl.expunge(VirtualMachineManagerImpl.java:428) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.destroyProxy(ConsoleProxyManagerImpl.java:1162) > at > com.cloud.server.ManagementServerImpl.destroyConsoleProxy(ManagementServerImpl.java:2147) > at > com.cloud.server.ManagementServerImpl.destroySystemVM(ManagementServerImpl.java:3205) > at > com.cloud.server.ManagementServerImpl.destroySystemVM(ManagementServerImpl.java:607) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:616) > at > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > at > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at sun.proxy.$Proxy225.destroySystemVM(Unknown Source) > at > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd.execute(DestroySystemVmCmd.java:97) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161) > at > com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109) > at > com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > at > com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63) > at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:520) > at > org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > at > org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-12-04 05:40:12,047 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Job-Executor-30:ctx-d6a82988) Complete async job-45, jobStatus: FAILED, > resultCode: 530, result: > org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable > to stop VM[ConsoleProxy|v-2-VM]"} > 2013-12-04 05:40:12,056 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Job-Executor-30:ctx-d6a82988) Done executing > org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd for job-45 > 2013-12-04 05:40:12,060 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (Job-Executor-30:ctx-d6a82988) Remove job-45 from job monitoring -- This message was sent by Atlassian JIRA (v6.1#6144)