Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1287771

Summary: [cinder] image is locked infinitely after engine restart was performed, during a make template of a VM with cinder disks
Product: [oVirt] ovirt-engine Reporter: Natalie Gavrielov <ngavrilo>
Component: BLL.StorageAssignee: Daniel Erez <derez>
Status: CLOSED CURRENTRELEASE QA Contact: Natalie Gavrielov <ngavrilo>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.6.1CC: ahadas, amureini, bugs, derez, gklein, stirabos, tnisan, ylavi
Target Milestone: ovirt-3.6.2Flags: rule-engine: ovirt-3.6.z+
rule-engine: blocker+
ylavi: planning_ack+
tnisan: devel_ack+
rule-engine: testing_ack+
Target Release: 3.6.2.5   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-02-18 11:03:52 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:
Attachments:
Description Flags
snapshot, engine.log, vdsm.log, cinder logs, ceph.log none

Description Natalie Gavrielov 2015-12-02 15:57:55 UTC
Created attachment 1101539 [details]
snapshot, engine.log, vdsm.log, cinder logs, ceph.log

Description of problem:

When performing an engine restart during template creation of a VM with cinder/ceph disks, operation locks the image infinitely (webadmin shows image is locked, and engine.log shows EJBTransactionRolledbackException)

Version-Release number of selected component (if applicable):
rhevm-3.6.1-0.2.el6.noarch


How reproducible:

Not always, because it depends on when performing the engine restart.

Steps to Reproduce:
1. Create a VM, with a few cinder-ceph disks, and install an OS.
2. Make a template out of the VM.
3. Meanwhile restart the engine.

Actual results:

* Webadmin shows image is locked (foerever). 
* Cinder / Ceph shows volumes were created:
volume-4d2906a1-b1f6-4ca3-bef6-a00399126a89
volume-64b93e0d-2390-4e3d-9ea6-37ff4667488a
volume-a65fd80f-2b4e-4312-9351-56b3497d078a
volume-b167c930-3f27-4701-8cde-600ff97e7886
volume-c5ed6936-ea56-49e6-af4f-268de57bf110
volume-e2a1e8cf-aab2-4f6e-a076-c689102594df
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
|                  ID                  |   Status  | Display Name | Size | Volume Type | Bootable | Attached to |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
| 4d2906a1-b1f6-4ca3-bef6-a00399126a89 | available |  svr_Disk2   |  7   |     ceph    |  false   |             |
| 64b93e0d-2390-4e3d-9ea6-37ff4667488a | available |  svr_Disk3   |  5   |     ceph    |  false   |             |
| a65fd80f-2b4e-4312-9351-56b3497d078a | available |  svr_Disk1   |  12  |     ceph    |  false   |             |
| b167c930-3f27-4701-8cde-600ff97e7886 | available |  svr_Disk1   |  12  |     ceph    |  false   |             |
| c5ed6936-ea56-49e6-af4f-268de57bf110 | available |  svr_Disk3   |  5   |     ceph    |  false   |             |
| e2a1e8cf-aab2-4f6e-a076-c689102594df | available |  svr_Disk2   |  7   |     ceph    |  false   |             |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+ 


* Rollback failed, engine.log:

2015-12-02 14:31:25,671 ERROR [org.ovirt.engine.core.bll.tasks.CommandExecutor] (DefaultQuartzScheduler_Worker-17) [] Error invoking callback method 'onFailed' for 'FAILED' command 'ac3f98af-e171-418a-9972-4a2bbb6f679f'

2015-12-02 14:31:24,230 ERROR [org.ovirt.engine.core.bll.tasks.CommandExecutor] (DefaultQuartzScheduler_Worker-13) [] Exception: javax.ejb.EJBTransactionRolledbackException
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleInCallerTx(CMTTxInterceptor.java:160) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:259) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:379) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:246) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view3.endAction(Unknown Source) [bll.jar:]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497) [rt.jar:1.8.0_65]
	at org.jboss.weld.util.reflection.SecureReflections$13.work(SecureReflections.java:267) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.util.reflection.SecureReflectionAccess.run(SecureReflectionAccess.java:52) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.util.reflection.SecureReflectionAccess.runAsInvocation(SecureReflectionAccess.java:137) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.util.reflection.SecureReflections.invoke(SecureReflections.java:263) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:115) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:105) [weld-core.jar:1.1.31.Final-redhat-1]
	at org.ovirt.engine.core.bll.BackendCommandObjectsHandler$BackendInternal$BackendLocal$142795634$Proxy$_$$_Weld$Proxy$.endAction(BackendCommandObjectsHandler$BackendInternal$BackendLocal$142795634$Proxy$_$$_Weld$Proxy$.java) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.CloneCinderDisksCommand.endSuccessfully(CloneCinderDisksCommand.java:86) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:647) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:591) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1981) [bll.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:210) [utils.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:149) [utils.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:118) [utils.jar:]
	at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:520) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.CloneCinderDisksCommandCallback.onSucceeded(CloneCinderDisksCommandCallback.java:49) [bll.jar:]
	at org.ovirt.engine.core.bll.tasks.CommandExecutor.invokeCallbackMethods(CommandExecutor.java:100) [bll.jar:]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497) [rt.jar:1.8.0_65]
	at org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81) [scheduler.jar:]
	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52) [scheduler.jar:]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]
Caused by: java.lang.NullPointerException
	at org.ovirt.engine.core.bll.Backend.endAction(Backend.java:500) [bll.jar:]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497) [rt.jar:1.8.0_65]
	at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:74) [jboss-as-weld.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:84) [jboss-as-weld.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:97) [jboss-as-weld.jar:7.5.5.Final-redhat-3]
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497) [rt.jar:1.8.0_65]
	at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:93) [jboss-as-weld.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:257) [jboss-as-ejb3.jar:7.5.5.Final-redhat-3]
	... 52 more

Expected results:

Either rollback or roll forward.

Comment 1 Allon Mureinik 2015-12-03 08:07:39 UTC
negative scenario, with an easy workaround for the customer - reducing severity.

Comment 2 Red Hat Bugzilla Rules Engine 2015-12-03 08:07:40 UTC
This bug is marked for z-stream, yet the milestone is for a major version, therefore the milestone has been reset.
Please set the correct milestone or drop the z stream flag.

Comment 3 Red Hat Bugzilla Rules Engine 2015-12-22 13:44:36 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 4 Sandro Bonazzola 2015-12-23 15:07:56 UTC
This bug has target milestone 3.6.2 and is on modified without a target release.
This may be perfectly correct, but please check if the patch fixing this bug is included in ovirt-engine-3.6.2. If it's included, please set target-release to 3.6.2 and move to ON_QA. Thanks.

Comment 5 Red Hat Bugzilla Rules Engine 2015-12-23 16:49:57 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 6 Natalie Gavrielov 2016-02-07 16:49:06 UTC
Verified, rhevm-3.6.3-0.1.el6.noarch
Ran the scenario (described in comment #0) 4 times:
In one of the runs a template wasn't created (probably restarted too early, so it rolled back).
and rest of the runs created templates.