1447050 – Snapshot remains in locked status after async delete using api (only when using async)

Bug 1447050 - Snapshot remains in locked status after async delete using api (only when using async)

Summary: Snapshot remains in locked status after async delete using api (only when usi...

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	ovirt-engine
Classification:	oVirt
Component:	BLL.Storage
Sub Component:
Version:	future
Hardware:	All
OS:	Linux
Priority:	unspecified
Severity:	high
Target Milestone:	ovirt-4.1.2
Target Release:	---
Assignee:	Ala Hino
QA Contact:	Kevin Alon Goldblatt
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	1445263
TreeView+	depends on / blocked

Reported:	2017-05-01 13:13 UTC by Ala Hino
Modified:	2019-04-28 13:53 UTC (History)
CC List:	13 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:	1445263
Environment:
Last Closed:	2017-05-23 08:17:10 UTC
oVirt Team:	Storage
Embargoed:
Dependent Products:
Flags:	rule-engine: ovirt-4.1+

Attachments	(Terms of Use)
server. engine, vdsm logs (1.28 MB, application/x-gzip) 2017-05-17 17:00 UTC, Kevin Alon Goldblatt	no flags	Details
server. engine, vdsm logs (869.71 KB, application/x-gzip) 2017-05-17 20:30 UTC, Kevin Alon Goldblatt	no flags	Details
View All

Links
System	ID	Private	Priority	Status	Summary	Last Updated
oVirt gerrit	76249	0	master	MERGED	async-command: Remove setting parent command	2017-05-08 14:05:34 UTC
oVirt gerrit	76673	0	ovirt-engine-4.1	MERGED	async-command: Remove setting parent command	2017-05-10 15:00:25 UTC

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!

Note You need to log in before you can comment on or make changes to this bug.