You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Animesh Chaturvedi (JIRA)" <ji...@apache.org> on 2013/12/31 19:43:53 UTC
[jira] [Updated] (CLOUDSTACK-5675) Destory VM is failing with
"Unable to delete vm snapshots for VM"
[ https://issues.apache.org/jira/browse/CLOUDSTACK-5675?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Animesh Chaturvedi updated CLOUDSTACK-5675:
-------------------------------------------
Assignee: Devdeep Singh
> Destory VM is failing with "Unable to delete vm snapshots for VM"
> ------------------------------------------------------------------
>
> Key: CLOUDSTACK-5675
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5675
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Management Server
> Affects Versions: 4.3.0
> Environment: Hyperv , 4.3
> Reporter: Abhinav Roy
> Assignee: Devdeep Singh
> Priority: Blocker
> Fix For: 4.3.0
>
>
> Steps :
> ===========================
> 1. Deploy a CS advanced zone setup with Hyper-V as hypervisor type
> 2. Create a VM
> 3. Destroy the VM
> Expected result:
> ==========================
> The VM should be created and destroyed successfully.
> Observed result :
> =========================
> Destroy VM fails with :
> 2013-12-30 15:02:30,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-57d2f51b) ===START=== 10.144.7.20 -- GET command=destroyVirtualMachine&response=json&sessionkey=P7hUEU1kTW2jFEVpcBKYxFUSxx4%3D&id=706fae35-94d2-414d-94da-8c7b21051edd&expunge=true&_=1388396154899
> 2013-12-30 15:02:30,344 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-57d2f51b ctx-03d0a162) submit async job-38, details: AsyncJobVO {id:38, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdInfo: {"response":"json","id":"706fae35-94d2-414d-94da-8c7b21051edd","sessionkey":"P7hUEU1kTW2jFEVpcBKYxFUSxx4\u003d","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1388396154899","ctxAccountId":"2","expunge":"true","ctxStartEventId":"108"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 280320865129348, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-12-30 15:02:30,344 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-57d2f51b ctx-03d0a162) ===END=== 10.144.7.20 -- GET command=destroyVirtualMachine&response=json&sessionkey=P7hUEU1kTW2jFEVpcBKYxFUSxx4%3D&id=706fae35-94d2-414d-94da-8c7b21051edd&expunge=true&_=1388396154899
> 2013-12-30 15:02:30,346 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-41:ctx-90d46ce0) Add job-38 into job monitoring
> 2013-12-30 15:02:30,346 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-41:ctx-90d46ce0) Executing AsyncJobVO {id:38, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdInfo: {"response":"json","id":"706fae35-94d2-414d-94da-8c7b21051edd","sessionkey":"P7hUEU1kTW2jFEVpcBKYxFUSxx4\u003d","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1388396154899","ctxAccountId":"2","expunge":"true","ctxStartEventId":"108"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 280320865129348, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-12-30 15:02:30,371 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-41:ctx-90d46ce0 ctx-03d0a162) Destroying vm VM[User|av3]
> 2013-12-30 15:02:30,372 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-41:ctx-90d46ce0 ctx-03d0a162) Stopped called on VM[User|av3] but the state is Error
> 2013-12-30 15:02:30,404 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-41:ctx-90d46ce0 ctx-03d0a162) Sync job-39 execution on object VmWorkJobQueue.6
> 2013-12-30 15:02:31,064 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-1f663345) StorageCollector is running...
> 2013-12-30 15:02:31,125 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-1f663345) Seq 2-1575288891: Received: { Ans: , MgmtId: 280320865129348, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-12-30 15:02:31,127 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-15:ctx-9d56111c) Seq 1-2099445910: Executing request
> 2013-12-30 15:02:31,128 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-15:ctx-9d56111c) POST request tohttp://10.102.192.14:8250/api/HypervResource/com.cloud.agent.api.GetStorageStatsCommand with contents{"id":"b183fb1d-c446-3a6f-b7ee-ec18507f39ae","localPath":"/HYPERV-SMB/abhinav-hyperv-ps1?user\u003dabhinav\u0026password\u003dfreebsd@123\u0026domain\u003dBLR","pooltype":"NetworkFilesystem","contextMap":{},"wait":0}
> 2013-12-30 15:02:31,128 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-15:ctx-9d56111c) Sending cmd to http://10.102.192.14:8250/api/HypervResource/com.cloud.agent.api.GetStorageStatsCommand cmd data:{"id":"b183fb1d-c446-3a6f-b7ee-ec18507f39ae","localPath":"/HYPERV-SMB/abhinav-hyperv-ps1?user\u003dabhinav\u0026password\u003dfreebsd@123\u0026domain\u003dBLR","pooltype":"NetworkFilesystem","contextMap":{},"wait":0}
> 2013-12-30 15:02:31,136 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-15:ctx-9d56111c) POST response is[{"com.cloud.agent.api.GetStorageStatsAnswer":{"result":false,"details":"com.cloud.agent.api.GetStorageStatsCommand failed on exceptionIllegal characters in path.","capacity":0,"used":0,"contextMap":{}}}]
> 2013-12-30 15:02:31,136 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-15:ctx-9d56111c) executeRequest received response [{"com.cloud.agent.api.GetStorageStatsAnswer":{"used":0,"capacity":0,"result":false,"details":"com.cloud.agent.api.GetStorageStatsCommand failed on exceptionIllegal characters in path.","contextMap":{},"wait":0}}]
> 2013-12-30 15:02:31,136 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-15:ctx-9d56111c) Seq 1-2099445910: Response Received:
> 2013-12-30 15:02:31,136 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-1f663345) Seq 1-2099445910: Received: { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-12-30 15:02:31,670 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-67d1aea0) Execute sync-queue item: SyncQueueItemVO {id:6, queueId: 5, contentType: AsyncJob, contentId: 39, lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null, created: Mon Dec 30 15:02:30 IST 2013}
> 2013-12-30 15:02:31,671 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-67d1aea0) Schedule queued job-39
> 2013-12-30 15:02:31,680 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-42:ctx-bd9d975c) Add job-39 into job monitoring
> 2013-12-30 15:02:31,680 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-42:ctx-bd9d975c) Executing AsyncJobVO {id:39, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAAAZ0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 280320865129348, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Dec 30 15:02:30 IST 2013}
> 2013-12-30 15:02:31,681 DEBUG [c.c.v.VmWorkJobDispatcher] (Job-Executor-42:ctx-bd9d975c) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots
> 2013-12-30 15:02:31,683 DEBUG [c.c.v.s.VMSnapshotManagerImpl] (Job-Executor-42:ctx-bd9d975c ctx-03d0a162) Execute Delete-All-VM-Snapshot within VM work job context. vmId: 6
> 2013-12-30 15:02:31,685 DEBUG [c.c.v.s.VMSnapshotManagerImpl] (Job-Executor-42:ctx-bd9d975c ctx-03d0a162) Execute Delete-All-VM-Snapshot within VM work job context. vmId: 6
> 2013-12-30 15:02:31,685 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-42:ctx-bd9d975c ctx-03d0a162) Complete async job-39, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
> 2013-12-30 15:02:31,691 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-42:ctx-bd9d975c) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-39
> 2013-12-30 15:02:31,698 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-41:ctx-90d46ce0 ctx-03d0a162) Unable to delete all snapshots for VM[User|av3]
> 2013-12-30 15:02:31,702 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Job-Executor-42:ctx-bd9d975c) Sync queue (5) is currently empty
> 2013-12-30 15:02:31,702 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-43:ctx-99262af7) Add job-38 into job monitoring
> 2013-12-30 15:02:31,702 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-43:ctx-99262af7) Executing AsyncJobVO {id:38, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdInfo: {"response":"json","id":"706fae35-94d2-414d-94da-8c7b21051edd","sessionkey":"P7hUEU1kTW2jFEVpcBKYxFUSxx4\u003d","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1388396154899","ctxAccountId":"2","expunge":"true","ctxStartEventId":"108"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 280320865129348, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Dec 30 15:02:30 IST 2013}
> 2013-12-30 15:02:31,703 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-42:ctx-bd9d975c) Remove job-39 from job monitoring
> 2013-12-30 15:02:31,705 ERROR [c.c.a.ApiAsyncJobDispatcher] (Job-Executor-41:ctx-90d46ce0) Unexpected exception while executing org.apache.cloudstack.api.command.user.vm.DestroyVMCmd
> com.cloud.utils.exception.CloudRuntimeException: Unable to delete vm snapshots for VM[User|av3]
> at com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1528)
> at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:256)
> at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:223)
> at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:3616)
> at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2085)
> 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 $Proxy169.destroyVm(Unknown Source)
> at org.apache.cloudstack.api.command.user.vm.DestroyVMCmd.execute(DestroyVMCmd.java:112)
> 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:522)
> 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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
> at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:522)
> 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:1110)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-12-30 15:02:31,709 WARN [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-43:ctx-99262af7) job-38 is scheduled for wakeup run, but there is no joining info anymore
> 2013-12-30 15:02:31,714 ERROR [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-43:ctx-99262af7) Unable to find a wakeup dispatcher from the joined job: AsyncJobVO {id:38, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdInfo: {"response":"json","id":"706fae35-94d2-414d-94da-8c7b21051edd","sessionkey":"P7hUEU1kTW2jFEVpcBKYxFUSxx4\u003d","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1388396154899","ctxAccountId":"2","expunge":"true","ctxStartEventId":"108"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 280320865129348, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Dec 30 15:02:30 IST 2013}
> 2013-12-30 15:02:31,714 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-43:ctx-99262af7) Done executing org.apache.cloudstack.api.command.user.vm.DestroyVMCmd for job-38
> 2013-12-30 15:02:31,716 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-41:ctx-90d46ce0) Complete async job-38, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable to delete vm snapshots for VM[User|av3]"}
> 2013-12-30 15:02:31,718 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-43:ctx-99262af7) Remove job-38 from job monitoring
> Workaround :
> ========================
> Add a new entry in cloud.configurations table with
> vm.job.enabled set to "false"
> restart management server. After this Destroy VM works fine.
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)