Bug 966153 - engine: vm is stuck in CreateSnapshot step during SLM because engine fails to clean the createVolume task (ArrayIndexOutOfBoundsException: -1 error)
engine: vm is stuck in CreateSnapshot step during SLM because engine fails to...
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine (Show other bugs)
3.2.0
x86_64 Linux
unspecified Severity high
: ---
: 3.3.0
Assigned To: Daniel Erez
yeylon@redhat.com
storage
: ZStream
: 967490 (view as bug list)
Depends On: 987783
Blocks: 972695
  Show dependency treegraph
 
Reported: 2013-05-22 11:59 EDT by Dafna Ron
Modified: 2016-04-18 02:53 EDT (History)
12 users (show)

See Also:
Fixed In Version: is2
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 972695 (view as bug list)
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
logs (2.80 MB, application/x-gzip)
2013-05-22 11:59 EDT, Dafna Ron
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
oVirt gerrit 15133 None None None Never

  None (edit)
Description Dafna Ron 2013-05-22 11:59:57 EDT
Created attachment 751771 [details]
logs

Description of problem:

I restarted vdsm during End Command of CreateSnapshotCommand. 
engine gets a ArrayIndexOutOfBoundsException: -1 error. 
it does not report success or failure for the live migration but event log reports that the snapshot was created successfully and we free the vm 

Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vcdvf' has been completed.

I tried to live storage migrate the disk again to see if it's just an exception in the log but what happens is that we send the createVolume task and although its finished we do not clean it so the vm is stuck in that step forever. 


this bug might be related to 965676 but is in a different step and has different results. 

Version-Release number of selected component (if applicable):

sf17.1

How reproducible:

100%

Steps to Reproduce:
1. create a vm from snapshot and run it on spm. 
2. LSM the vm disk and when End Action of CreateSnapshotCommand is run restart the vdsm on spm
3. when vm lock is released LSM the disk again

Actual results:

the firs time we get ArrayIndexOutOfBoundsException: -1 but vm is freed. 
the second time engine fails to clean the createVolume task which is finished successfully and vm is locked in that step forever. 

Expected results:

we should not hey ArrayIndexOutOfBoundsException: -1  error. 

Additional info: logs

both tasks are shown in vdsm: 

ab69c85f-c506-4756-b269-5fb7e824ff7c :
        verb = createVolume
        id = ab69c85f-c506-4756-b269-5fb7e824ff7c
31689665-a832-47a7-a7e8-e62c516867c7 :
        verb = createVolume
        id = 31689665-a832-47a7-a7e8-e62c516867c7

{'status': {'message': 'OK', 'code': 0}, 'allTasksStatus': {'ab69c85f-c506-4756-b269-5fb7e824ff7c': {'message': '1 jobs completed successfully', 'code': 0, 'taskID': 'ab69c85f-c506-4756-b269-5fb7e824ff7c', 'taskResult': 'success', 'task
State': 'finished'}, '31689665-a832-47a7-a7e8-e62c516867c7': {'message': '1 jobs completed successfully', 'code': 0, 'taskID': '31689665-a832-47a7-a7e8-e62c516867c7', 'taskResult': 'success', 'taskState': 'finished'}}}




2013-05-22 18:12:35,051 ERROR [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (pool-4-thread-49) Ending command with failure: org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand
2013-05-22 18:12:35,055 ERROR [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-49) EntityAsyncTask::EndCommandAction [within thread]: EndAction for action type LiveMigrateVmDisks threw an exception: javax.ejb.EJBException: java.lang.ArrayIndexOutOfBoundsException: -1
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInNoTx(CMTTxInterceptor.java:191) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:237) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:374) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:218) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view8.endAction(Unknown Source) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.EntityAsyncTask.EndCommandAction(EntityAsyncTask.java:147) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.EntityAsyncTask.access$000(EntityAsyncTask.java:26) [engine-bll.jar:]
Comment 2 Tal Nisan 2013-07-09 07:52:14 EDT
*** Bug 967490 has been marked as a duplicate of this bug. ***
Comment 3 vvyazmin@redhat.com 2013-07-23 10:42:04 EDT
Can’t be verified, this bug depend on 987460, tested on RHEVM 3.3 - IS6 environment.
Comment 4 vvyazmin@redhat.com 2013-08-18 15:10:22 EDT
Tested on FCP Data Center

Verified, tested on RHEVM 3.3 - IS10 environment:

RHEVM:  rhevm-3.3.0-0.15.master.el6ev.noarch
PythonSDK:  rhevm-sdk-python-3.3.0.10-1.el6ev.noarch
VDSM:  vdsm-4.12.0-61.git8178ec2.el6ev.x86_64
LIBVIRT:  libvirt-0.10.2-18.el6_4.9.x86_64
QEMU & KVM:  qemu-kvm-rhev-0.12.1.2-2.355.el6_4.5.x86_64
SANLOCK:  sanlock-2.8-1.el6.x86_64
Comment 7 Itamar Heim 2014-01-21 17:27:10 EST
Closing - RHEV 3.3 Released
Comment 8 Itamar Heim 2014-01-21 17:27:38 EST
Closing - RHEV 3.3 Released
Comment 9 Itamar Heim 2014-01-21 17:30:20 EST
Closing - RHEV 3.3 Released

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