andrijapanicsb edited a comment on issue #3649: Garbage snapshots are left on Primary and Secondary URL: https://github.com/apache/cloudstack/pull/3649#issuecomment-583452735 thx @GabrielBrascher Update on KVM+NFS+ snapshot.backup.to.secondary=FALSE Created and kept on Primary Storage fine. When I attempt to delete the snap, the below exceptions is raised (and a short error in GUI as well), and the snap is NOT removed from QCOW2 file, but the snapshots_store_ref records (there is only one for PRIMARY store) get moved to "destroying" state. The full exception is as bellow: > 2020-02-07 15:23:47,440 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-114:ctx-9b53a159) (logid:8c989eae) Process host VM state report from ping process. host: 3 2020-02-07 15:23:47,442 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-114:ctx-9b53a159) (logid:8c989eae) Process VM state report. host: 3, number of records in report: 1 2020-02-07 15:23:47,442 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-114:ctx-9b53a159) (logid:8c989eae) VM state report. host: 3, vm id: 1, power state: PowerOn 2020-02-07 15:23:47,446 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-114:ctx-9b53a159) (logid:8c989eae) Done with process of VM state report. host: 3 2020-02-07 15:23:47,741 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-455:ctx-f92650fb) (logid:e1ad9755) Ping from 4(ref-trl-557-k-M7-bstoyanov-xs1) 2020-02-07 15:23:47,741 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-455:ctx-f92650fb) (logid:e1ad9755) Process host VM state report from ping process. host: 4 2020-02-07 15:23:47,744 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-455:ctx-f92650fb) (logid:e1ad9755) Process VM state report. host: 4, number of records in report: 1 2020-02-07 15:23:47,744 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-455:ctx-f92650fb) (logid:e1ad9755) VM state report. host: 4, vm id: 9, power state: PowerOn 2020-02-07 15:23:47,747 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-455:ctx-f92650fb) (logid:e1ad9755) Done with process of VM state report. host: 4 2020-02-07 15:23:49,923 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-3:null) (logid:) Ping from 8(s-2-VM) 2020-02-07 15:23:51,207 DEBUG [c.c.a.ApiServlet] (qtp504527234-11:ctx-3b3f5a95) (logid:325084b2) ===START=== 10.1.0.1 -- GET command=deleteSnapshot&id=0a9ffa09-6f48-4a54-ae29-7305970572a3&response=json&_=1581088628177 2020-02-07 15:23:51,215 DEBUG [c.c.a.ApiServer] (qtp504527234-11:ctx-3b3f5a95 ctx-73ad6744) (logid:325084b2) CIDRs from which account 'Acct[70becd07-4980-11ea-952a-1e00b30107e1-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2020-02-07 15:23:51,237 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-10:ctx-5071251e job-112) (logid:44496281) Add job-112 into job monitoring 2020-02-07 15:23:51,240 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp504527234-11:ctx-3b3f5a95 ctx-73ad6744) (logid:325084b2) submit async job-112, details: AsyncJobVO {id:112, userId: 2, accountId: 2, instanceType: Snapshot, instanceId: 14, cmd: org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd, cmdInfo: {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"237","id":"0a9ffa09-6f48-4a54-ae29-7305970572a3","ctxDetails":"{\"interface com.cloud.storage.Snapshot\":\"0a9ffa09-6f48-4a54-ae29-7305970572a3\"}","ctxAccountId":"2","uuid":"0a9ffa09-6f48-4a54-ae29-7305970572a3","cmdEventType":"SNAPSHOT.DELETE","_":"1581088628177"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32988352022497, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null} 2020-02-07 15:23:51,241 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Executing AsyncJobVO {id:112, userId: 2, accountId: 2, instanceType: Snapshot, instanceId: 14, cmd: org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd, cmdInfo: {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"237","id":"0a9ffa09-6f48-4a54-ae29-7305970572a3","ctxDetails":"{\"interface com.cloud.storage.Snapshot\":\"0a9ffa09-6f48-4a54-ae29-7305970572a3\"}","ctxAccountId":"2","uuid":"0a9ffa09-6f48-4a54-ae29-7305970572a3","cmdEventType":"SNAPSHOT.DELETE","_":"1581088628177"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32988352022497, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null} 2020-02-07 15:23:51,244 DEBUG [c.c.a.ApiServlet] (qtp504527234-11:ctx-3b3f5a95 ctx-73ad6744) (logid:325084b2) ===END=== 10.1.0.1 -- GET command=deleteSnapshot&id=0a9ffa09-6f48-4a54-ae29-7305970572a3&response=json&_=1581088628177 2020-02-07 15:23:51,279 DEBUG [o.a.c.s.s.DefaultSnapshotStrategy] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) delete snapshot chain for snapshot: 14 2020-02-07 15:23:51,281 DEBUG [o.a.c.s.s.DefaultSnapshotStrategy] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Snapshot: 14 doesn't have children, so it's ok to delete it and its parents 2020-02-07 15:23:51,282 DEBUG [o.a.c.s.s.SnapshotObject] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Failed to update state:com.cloud.utils.exception.CloudRuntimeException: can't find mapping in ObjectInDataStore table for: org.apache.cloudstack.storage.snapshot.SnapshotObject@2761608d 2020-02-07 15:23:51,283 DEBUG [o.a.c.s.s.DefaultSnapshotStrategy] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Failed to delete snapshot on storage. com.cloud.utils.exception.CloudRuntimeException: Failed to update state: com.cloud.utils.exception.CloudRuntimeException: can't find mapping in ObjectInDataStore table for: org.apache.cloudstack.storage.snapshot.SnapshotObject@2761608d at org.apache.cloudstack.storage.snapshot.SnapshotObject.processEvent(SnapshotObject.java:204) at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.deleteSnapshot(SnapshotServiceImpl.java:402) at org.apache.cloudstack.storage.snapshot.DefaultSnapshotStrategy.deleteSnapshotChain(DefaultSnapshotStrategy.java:206) at org.apache.cloudstack.storage.snapshot.DefaultSnapshotStrategy.deleteSnapshotOnSecundaryStorage(DefaultSnapshotStrategy.java:314) at org.apache.cloudstack.storage.snapshot.DefaultSnapshotStrategy.deleteSnapshot(DefaultSnapshotStrategy.java:273) at com.cloud.storage.snapshot.SnapshotManagerImpl.deleteSnapshot(SnapshotManagerImpl.java:588) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174) at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy199.deleteSnapshot(Unknown Source) at org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd.execute(DeleteSnapshotCmd.java:103) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156) at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583) 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 org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:531) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2020-02-07 15:23:51,288 DEBUG [o.a.c.s.s.DefaultSnapshotStrategy] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Failed to find/delete snapshot (id: 14) on secondary storage. Still necessary to check and delete snapshot on primary storage. 2020-02-07 15:23:51,319 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) getCommandHostDelegation: class org.apache.cloudstack.storage.command.DeleteCommand 2020-02-07 15:23:51,319 DEBUG [c.c.h.XenServerGuru] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) We are returning the default host to execute commands because the command is not of Copy type. 2020-02-07 15:23:51,321 DEBUG [c.c.a.t.Request] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Seq 6-5215168368495034555: Sending { Cmd , MgmtId: 32988352022497, via: 6(ref-trl-557-k-M7-bstoyanov-kvm2), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/c0155744-08ea-3551-bbca-44c847fe936a/c1f9abbd-61c6-41c8-a8b2-cc04767fd557/0438c56d-3bdf-442a-9f8b-b3146def73f2","volume":{"uuid":"c1f9abbd-61c6-41c8-a8b2-cc04767fd557","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c0155744-08ea-3551-bbca-44c847fe936a","id":4,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-557-k-M7-bstoyanov/ref-trl-557-k-M7-bstoyanov-kvm-pri2","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-557-k-M7-bstoyanov/ref-trl-557-k-M7-bstoyanov-kvm-pri2/?ROLE=Primary&STOREUUID=c0155744-08ea-3551-bbca-44c847fe936a","isManaged":false}},"name":"ROOT-8","size":8589934592,"path":"c1f9abbd-61c6-41c8-a8b2-cc04767fd557","volumeId":9,"vmName":"i-2-8-VM","accountId":2,"format":"QCOW2","provisioningType":"THIN","id":9,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c0155744-08ea-3551-bbca-44c847fe936a","id":4,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-557-k-M7-bstoyanov/ref-trl-557-k-M7-bstoyanov-kvm-pri2","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-557-k-M7-bstoyanov/ref-trl-557-k-M7-bstoyanov-kvm-pri2/?ROLE=Primary&STOREUUID=c0155744-08ea-3551-bbca-44c847fe936a","isManaged":false}},"vmName":"i-2-8-VM","name":"aaaaaaaaa","hypervisorType":"KVM","id":14,"quiescevm":false,"physicalSize":0}},"wait":0}}] } 2020-02-07 15:23:51,497 DEBUG [c.c.a.t.Request] (AgentManager-Handler-20:null) (logid:) Seq 6-5215168368495034555: Processing: { Ans: , MgmtId: 32988352022497, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"Failed to remove snapshot c1f9abbd-61c6-41c8-a8b2-cc04767fd557@0438c56d-3bdf-442a-9f8b-b3146def73f2","wait":0}}] } 2020-02-07 15:23:51,498 DEBUG [c.c.a.t.Request] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Seq 6-5215168368495034555: Received: { Ans: , MgmtId: 32988352022497, via: 6(ref-trl-557-k-M7-bstoyanov-kvm2), Ver: v1, Flags: 10, { Answer } } 2020-02-07 15:23:51,498 DEBUG [o.a.c.s.s.SnapshotServiceImpl] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) delete snapshot failedFailed to remove snapshot c1f9abbd-61c6-41c8-a8b2-cc04767fd557@0438c56d-3bdf-442a-9f8b-b3146def73f2 2020-02-07 15:23:51,504 DEBUG [c.c.s.s.SnapshotManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112 ctx-536c93db) (logid:d6e031b9) Failed to delete snapshot: 14:com.cloud.utils.exception.CloudRuntimeException: Failed to remove snapshot c1f9abbd-61c6-41c8-a8b2-cc04767fd557@0438c56d-3bdf-442a-9f8b-b3146def73f2 2020-02-07 15:23:51,511 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Unexpected exception while executing org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd com.cloud.utils.exception.CloudRuntimeException: Failed to delete snapshot:com.cloud.utils.exception.CloudRuntimeException: Failed to remove snapshot c1f9abbd-61c6-41c8-a8b2-cc04767fd557@0438c56d-3bdf-442a-9f8b-b3146def73f2 at com.cloud.storage.snapshot.SnapshotManagerImpl.deleteSnapshot(SnapshotManagerImpl.java:611) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174) at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy199.deleteSnapshot(Unknown Source) at org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd.execute(DeleteSnapshotCmd.java:103) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156) at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583) 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 org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:531) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2020-02-07 15:23:51,512 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Complete async job-112, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to delete snapshot:com.cloud.utils.exception.CloudRuntimeException: Failed to remove snapshot c1f9abbd-61c6-41c8-a8b2-cc04767fd557@0438c56d-3bdf-442a-9f8b-b3146def73f2"} 2020-02-07 15:23:51,513 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Publish async job-112 complete on message bus 2020-02-07 15:23:51,513 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Wake up jobs related to job-112 2020-02-07 15:23:51,513 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Update db status for job-112 2020-02-07 15:23:51,514 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Wake up jobs joined with job-112 and disjoin all subjobs created from job- 112 2020-02-07 15:23:51,523 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Done executing org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd for job-112 2020-02-07 15:23:51,523 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-10:ctx-5071251e job-112) (logid:d6e031b9) Remove job-112 from job monitoring`
---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services
