You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sanjeev N (JIRA)" <ji...@apache.org> on 2013/12/04 06:36:35 UTC
[jira] [Updated] (CLOUDSTACK-5360) [Hyper-V] Failed to stop/destroy
system vms
[ https://issues.apache.org/jira/browse/CLOUDSTACK-5360?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sanjeev N updated CLOUDSTACK-5360:
----------------------------------
Attachment: management-server.rar
> [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)