Bug 1447050

Summary: Snapshot remains in locked status after async delete using api (only when using async)
Product: [oVirt] ovirt-engine Reporter: Ala Hino <ahino>
Component: BLL.StorageAssignee: Ala Hino <ahino>
Status: CLOSED CURRENTRELEASE QA Contact: Kevin Alon Goldblatt <kgoldbla>
Severity: high Docs Contact:
Priority: unspecified    
Version: futureCC: amureini, bugs, kgoldbla, lsurette, mavital, mwest, nashok, rbalakri, Rhev-m-bugs, srevivo, tnisan, ykaul, ylavi
Target Milestone: ovirt-4.1.2Flags: rule-engine: ovirt-4.1+
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1445263 Environment:
Last Closed: 2017-05-23 08:17:10 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1445263    
Attachments:
Description Flags
server. engine, vdsm logs
none
server. engine, vdsm logs none

Comment 6 Kevin Alon Goldblatt 2017-05-17 16:54:12 UTC
Verify with the following code:
------------------------------------------
ovirt-engine-4.1.2.1-0.1.el7.noarch
rhevm-4.1.2.1-0.1.el7.noarch
vdsm-4.19.14-1.el7ev.x86_64

Verify with the following scenario:
------------------------------------------
https://xxx.xxx.com/ovirt-engine/api/vms/b786ea5d-2c7f-421f-9233-fc2da8f3b876/snapshots/30dbf5c6-5dc3-47bf-8d82-2b6baf9cc071;async=true

Engine.log
------------------------------------------
2017-05-17 19:33:35,166+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-5-thread-1) [] EVENT_ID: USER_REMOVE_SNAPSHOT(342), Correlation ID: 24232ded-a2f5-41cc-bba2-e9e5095a0
8e2, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'sna4' deletion for VM 'vm5' was initiated by admin@internal-authz.
2017-05-17 19:33:35,241+03 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Command 'RemoveSnapshot' (id: 'f6fd2895-efa3
-4091-a5e3-54e10f296487') waiting on child command id: 'cf998296-c792-4ba4-a0e5-2814daa3df5d' type:'RemoveSnapshotSingleDiskLive' to complete
2017-05-17 19:33:35,272+03 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler6) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Executing Live Merge command step 'EXTE
ND'
2017-05-17 19:33:35,389+03 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Command 'RunAsyncAction' (id: '558bead8-b2cf-4826-b832-7b0a57be0323') waiting on child command id: 'f6fd2895-efa3-4091-a5e3-54e10f296487' type:'RemoveSnapshot' to complete
2017-05-17 19:33:35,451+03 INFO  [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-5-thread-3) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Running command: MergeExtendCommand internal: true. Entities affected :  ID: a547f532-ccdf-4c09-92e5-2a2c42519b2a Type: Storage
2017-05-17 19:33:35,452+03 INFO  [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-5-thread-3) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Base and top image sizes are the same; no image size update required
2017-05-17 19:33:36,446+03 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Executing Live Merge command step 'MERGE'
.
.
.
.
2017-05-17 19:34:33,236+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Failed in 'GetVolumeInfoVDS' method
2017-05-17 19:34:33,240+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand' return value '
VolumeInfoReturn:{status='Status [code=201, message=Volume does not exist: ('5fb482f3-fd17-4843-9671-cc0e765db677',)]'}
'
2017-05-17 19:34:33,241+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] HostName = purple-vds1.qa.lab.tlv.redhat.com
2017-05-17 19:34:33,241+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] Command 'GetVolumeInfoVDSCommand(HostName = purple-vds1.qa.lab.tlv.redhat.com, GetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', hostId='8bc4dd20-af5e-40fa-babf-359c074ffc43', storagePoolId='00000001-0001-0001-0001-000000000311', storageDomainId='a547f532-ccdf-4c09-92e5-2a2c42519b2a', imageGroupId='bd26cd5b-89c9-4ae2-9c73-b52b4fc2ddbb', imageId='5fb482f3-fd17-4843-9671-cc0e765db677'})' execution failed: VDSGenericException: VDSErrorException: Failed to GetVolumeInfoVDS, error = Volume does not exist: ('5fb482f3-fd17-4843-9671-cc0e765db677',), code = 201
2017-05-17 19:34:33,241+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] FINISH, GetVolumeInfoVDSCommand, log id: 4b8b18bd
2017-05-17 19:34:33,241+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-5-thread-7) [24232ded-a2f5-41cc-bba2-e9e5095a08e2] FINISH, SPMGetVolumeInfoVDSCommand, log id: 5afcf71c

Comment 7 Red Hat Bugzilla Rules Engine 2017-05-17 16:54:22 UTC
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.

Comment 8 Kevin Alon Goldblatt 2017-05-17 17:00:51 UTC
Created attachment 1279759 [details]
server. engine, vdsm logs

Added logs

The scenario was as follows:
------------------------------------
1. Ran delete snapshot via the API:
https://kevin-rhevm.scl.lab.tlv.redhat.com/ovirt-engine/api/vms/b786ea5d-2c7f-421f-9233-fc2da8f3b876/snapshots/30dbf5c6-5dc3-47bf-8d82-2b6baf9cc071;async=true

>>>>The snapshot remains locked

Comment 9 Ala Hino 2017-05-17 18:36:49 UTC
Kevin,

The build containing the patch fixing this bug is ovirt-engine-4.1.2.2 (not 4.1.2.1).
Please note that the corresponding downstream bug (BZ 1449750) is already verified by ipinto.

Moving back to ON_QA.

Comment 10 Kevin Alon Goldblatt 2017-05-17 20:27:08 UTC
Tested again with the correct code:
--------------------------------------------
ovirt-engine-4.1.2.2-0.1.el7.noarch
rhevm-4.1.2.2-0.1.el7.noarch

The scenario was as follows:
------------------------------------
1. Ran delete snapshot via the API:
https://kevin-rhevm.scl.lab.tlv.redhat.com/ovirt-engine/api/vms/b786ea5d-2c7f-421f-9233-fc2da8f3b876/snapshots/30dbf5c6-5dc3-47bf-8d82-2b6baf9cc071;async=true


The snapshot failed to delete but was not locked

Moving to assigned!

Comment 11 Kevin Alon Goldblatt 2017-05-17 20:30:51 UTC
Created attachment 1279785 [details]
server. engine, vdsm logs

Added new logs

Comment 12 Kevin Alon Goldblatt 2017-05-17 20:47:24 UTC
Adding engine log output
---------------------------
2017-05-17 23:22:13,376+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Failed in 'MergeVDS' method
2017-05-17 23:22:13,398+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM purple-vds1.qa.lab.tlv.redhat.com command MergeVDS failed: Drive image file could not be found
2017-05-17 23:22:13,399+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand' return value 'StatusOnlyReturn [status=Status [code=13, message=Drive image file could not be found]]'
2017-05-17 23:22:13,399+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] HostName = purple-vds1.qa.lab.tlv.redhat.com
2017-05-17 23:22:13,399+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command 'MergeVDSCommand(HostName = purple-vds1.qa.lab.tlv.redhat.com, MergeVDSCommandParameters:{runAsync='true', hostId='8bc4dd20-af5e-40fa-babf-359c074ffc43', vmId='a550d66a-1179-4e0e-ac31-7f993e9af850', storagePoolId='00000001-0001-0001-0001-000000000311', storageDomainId='5f6e0626-3a8c-41ed-b843-7a9290a4db5a', imageGroupId='b8fe4444-9e5e-4802-ab0f-1a3d8e1bc567', imageId='cbdf3931-0239-4033-b0d6-86c694b871d4', baseImageId='a3adefec-4939-4c85-b680-a240a0b232b7', topImageId='cbdf3931-0239-4033-b0d6-86c694b871d4', bandwidth='0'})' execution failed: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Drive image file could not be found, code = 13
2017-05-17 23:22:13,399+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] FINISH, MergeVDSCommand, log id: 735b2e93
2017-05-17 23:22:13,400+03 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Engine exception thrown while sending merge command: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Drive image file could not be found, code = 13 (Failed with error imageErr and code 13)
        at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:]
        at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2166) [bll.jar:]
        at org.ovirt.engine.core.bll.MergeCommand.executeCommand(MergeCommand.java:45) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1251) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1391) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2055) [bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105) [utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1451) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:397) [bll.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendActionExecutor.execute(DefaultBackendActionExecutor.java:13) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:511) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:756) [bll.jar:]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_131]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:70) [wildfly-weld-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:80) [wildfly-weld-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93) [wildfly-weld-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
        at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor128.invoke(Unknown Source) [:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
:
.
.
.
       at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66) [wildfly-ejb3-7.0.5.GA-redhat-2.jar:7.0.5.GA-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
        at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
        at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
        at org.ovirt.engine.core.bll.interfaces.BackendCommandObjectsHandler$$$view4.runAction(Unknown Source) [bll.jar:]
        at org.ovirt.engine.core.bll.tasks.CommandExecutor.executeCommand(CommandExecutor.java:57) [bll.jar:]
        at org.ovirt.engine.core.bll.tasks.CommandExecutor.lambda$executeAsyncCommand$0(CommandExecutor.java:46) [bll.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
        at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
Caused by: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Drive image file could not be found, code = 13
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:76) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:222) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:192) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand.executeVdsBrokerCommand(MergeVDSCommand.java:26) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:111) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73) [vdsbroker.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:407) [vdsbroker.jar:]
        ... 88 more
.
.
.
2017-05-17 23:22:17,013+03 ERROR [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-5-thread-8) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Failed to live merge, still in volume chain: []
2017-05-17 23:22:17,412+03 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command 'RemoveSnapshot' (id: '2164d804-a96b-48dc-bfc0-e21cf197db9d') waiting on child command id: 'e7f0d3be-476e-4d3d-ad1a-c8dd9175c56c' type:'RemoveSnapshotSingleDiskLive' to complete
2017-05-17 23:22:17,435+03 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler6) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command id: 'e7f0d3be-476e-4d3d-ad1a-c8dd9175c56c failed child command status for step 'MERGE_STATUS'
2017-05-17 23:22:17,435+03 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback] (DefaultQuartzScheduler6) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command 'RemoveSnapshotSingleDiskLive' id: 'e7f0d3be-476e-4d3d-ad1a-c8dd9175c56c' child commands '[f2393f06-a439-44f0-843f-cf439a6b3f25, 12f02563-e4c9-4ded-99aa-f5e5b2d08d73, 63e41772-e61a-43c2-9f23-4baf3c39e184]' executions were completed, status 'FAILED'
2017-05-17 23:22:18,486+03 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback] (DefaultQuartzScheduler2) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Command 'RemoveSnapshotSingleDiskLive' (id: 'd44458b8-35fb-4bd9-8c79-f4bdf508f030') waiting on child command id: '3e733701-99b7-41ed-851f-2ea435d53b8b' type:'Merge' to complete
2017-05-17 23:22:18,508+03 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler2) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Merging of snapshot '77ff813c-fcfe-4737-a6db-ecff9263c3d8' images 'a3adefec-4939-4c85-b680-a240a0b232b7'..'cbdf3931-0239-4033-b0d6-86c694b871d4' failed. Images have been marked illegal and can no longer be previewed or reverted to. Please retry Live Merge on the snapshot to complete the operation.
2017-05-17 23:22:18,531+03 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler2) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand' with failure.

Comment 13 Ala Hino 2017-05-17 20:50:40 UTC
I see unrelated errors in the engine log:

2017-05-17 23:22:13,400+03 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-5-thread-7) [6888ae6f-1a9b-422c-a0dc-5c77fbaf8b44] Engine exception thrown while sending merge command: org.ov
irt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error
 = Drive image file could not be found, code = 13 (Failed with error imageErr and code 13)
        at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:]
        at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:]

Considering this exception, the snapshot isn't deleted and shouldn't be locked.


Can you please try the same scenario in a clean setup? Just create a new VM and try to create and delete a snapshot.

Once again, this BZ was verified downstream, so something isn't right here, either you are doing something wrong or need to double check ipinto verification.

Comment 14 Kevin Alon Goldblatt 2017-05-18 15:47:37 UTC
Verfied again with a clean system and same code


moving to VERIFIED!