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.Storage | Assignee: | Ala Hino <ahino> | ||||||
Status: | CLOSED CURRENTRELEASE | QA Contact: | Kevin Alon Goldblatt <kgoldbla> | ||||||
Severity: | high | Docs Contact: | |||||||
Priority: | unspecified | ||||||||
Version: | future | CC: | amureini, bugs, kgoldbla, lsurette, mavital, mwest, nashok, rbalakri, Rhev-m-bugs, srevivo, tnisan, ykaul, ylavi | ||||||
Target Milestone: | ovirt-4.1.2 | Flags: | 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: |
|
Comment 6
Kevin Alon Goldblatt
2017-05-17 16:54:12 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. 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 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. 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! Created attachment 1279785 [details]
server. engine, vdsm logs
Added new logs
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. 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. Verfied again with a clean system and same code moving to VERIFIED! |