Bug 921202

Summary: ovirt-engine: remove storage pool is failing in Psql exception: Failed to run compensation on startup for Command org.ovirt.engine.core.bll.storage.RemoveStoragePoolCommand, Com mand Id : 076abb88-ead3-4a87-9d31-a534f41ad127, due to: DataIntegrityViolatio
Product: Red Hat Enterprise Virtualization Manager Reporter: Haim <hateya>
Component: ovirt-engineAssignee: Eli Mesika <emesika>
Status: CLOSED CURRENTRELEASE QA Contact: Elad <ebenahar>
Severity: high Docs Contact:
Priority: urgent    
Version: 3.1.3CC: acathrow, alourie, dyasny, emesika, hateya, iheim, lpeer, Rhev-m-bugs, sgrinber, yeylon, ykaul, yzaslavs
Target Milestone: ---   
Target Release: 3.2.0   
Hardware: x86_64   
OS: Linux   
Whiteboard: infra
Fixed In Version: sf11 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 921201, 948448, 949694    
Attachments:
Description Flags
engine.log none

Description Haim 2013-03-13 17:05:28 UTC
Description of problem:

I got this exception while trying to upgrade rhevm from si26.4 to si27.4, had few tasks left in async tasks table, engine asked if i want to stop them, replied positively, engine tried to stop the task and I got the following:

013-03-13 18:41:51,047 INFO  [org.ovirt.engine.core.bll.storage.RemoveStoragePoolCommand] (ServerService Thread Pool -- 38) Command [id=076abb88-ead3-4a87-9d31-a534f41ad127]: Compensating CHANGED_ENTITY of org.ov
irt.engine.core.common.businessentities.storage_pool_iso_map; snapshot: id=storagePoolId = eb59b1a9-37d2-427f-a158-bd2cdc7b11bc, storageId = b50d0b87-a954-42f3-afbf-a42ef8edc02e.
2013-03-13 18:41:51,106 INFO  [org.ovirt.engine.core.utils.transaction.TransactionSupport] (ServerService Thread Pool -- 38) transaction rolled back
2013-03-13 18:41:51,122 ERROR [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 38) Failed to run compensation on startup for Command org.ovirt.engine.core.bll.storage.RemoveStoragePoolCommand, Com
mand Id : 076abb88-ead3-4a87-9d31-a534f41ad127, due to: DataIntegrityViolationException: CallableStatementCallback; SQL [{call insertstorage_pool_iso_map(?, ?, ?, ?)}]; ERROR: insert or update on table "storage_po
ol_iso_map" violates foreign key constraint "fk_storage_domain_pool_map_storage_pool"
  Detail: Key (storage_pool_id)=(eb59b1a9-37d2-427f-a158-bd2cdc7b11bc) is not present in table "storage_pool".
  Where: SQL statement "INSERT INTO storage_pool_iso_map(storage_id, storage_pool_id, status, owner) VALUES( $1 ,  $2 ,  $3 ,  $4 )"
PL/pgSQL function "insertstorage_pool_iso_map" line 2 at SQL statement; nested exception is org.postgresql.util.PSQLException: ERROR: insert or update on table "storage_pool_iso_map" violates foreign key constrain
t "fk_storage_domain_pool_map_storage_pool"
  Detail: Key (storage_pool_id)=(eb59b1a9-37d2-427f-a158-bd2cdc7b11bc) is not present in table "storage_pool".
  Where: SQL statement "INSERT INTO storage_pool_iso_map(storage_id, storage_pool_id, status, owner) VALUES( $1 ,  $2 ,  $3 ,  $4 )"
PL/pgSQL function "insertstorage_pool_iso_map" line 2 at SQL statement: org.springframework.dao.DataIntegrityViolationException: CallableStatementCallback; SQL [{call insertstorage_pool_iso_map(?, ?, ?, ?)}]; ERROR: insert or update on table "storage_pool_iso_map" violates foreign key constraint "fk_storage_domain_pool_map_storage_pool"
  Detail: Key (storage_pool_id)=(eb59b1a9-37d2-427f-a158-bd2cdc7b11bc) is not present in table "storage_pool".
  Where: SQL statement "INSERT INTO storage_pool_iso_map(storage_id, storage_pool_id, status, owner) VALUES( $1 ,  $2 ,  $3 ,  $4 )"
PL/pgSQL function "insertstorage_pool_iso_map" line 2 at SQL statement; nested exception is org.postgresql.util.PSQLException: ERROR: insert or update on table "storage_pool_iso_map" violates foreign key constraint "fk_storage_domain_pool_map_storage_pool"
  Detail: Key (storage_pool_id)=(eb59b1a9-37d2-427f-a158-bd2cdc7b11bc) is not present in table "storage_pool".
  Where: SQL statement "INSERT INTO storage_pool_iso_map(storage_id, storage_pool_id, status, owner) VALUES( $1 ,  $2 ,  $3 ,  $4 )"
PL/pgSQL function "insertstorage_pool_iso_map" line 2 at SQL statement
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:245) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:1030) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.call(JdbcTemplate.java:1064) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.executeCallInternal(AbstractJdbcCall.java:388) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.simple.AbstractJdbcCall.doExecute(AbstractJdbcCall.java:351) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.simple.SimpleJdbcCall.execute(SimpleJdbcCall.java:181) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:124) [engine-dal.jar:]
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeModification(SimpleJdbcCallsHandler.java:37) [engine-dal.jar:]
        at org.ovirt.engine.core.dao.StoragePoolIsoMapDAODbFacadeImpl.save(StoragePoolIsoMapDAODbFacadeImpl.java:44) [engine-dal.jar:]
        at org.ovirt.engine.core.dao.StoragePoolIsoMapDAODbFacadeImpl.save(StoragePoolIsoMapDAODbFacadeImpl.java:15) [engine-dal.jar:]
        at org.ovirt.engine.core.bll.CommandBase$1.runInTransaction(CommandBase.java:374) [engine-bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:204) [engine-utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.internalCompensate(CommandBase.java:341) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.compensate(CommandBase.java:328) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.compensate(Backend.java:272) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.Initialize(Backend.java:168) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.create(Backend.java:119) [engine-bll.jar:]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_09-icedtea]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_09-icedtea]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_09-icedtea]
        at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_09-icedtea]
        at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:130) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ManagedReferenceFieldInjectionInterceptorFactory$ManagedReferenceFieldInjectionInterceptor.processInvocation(ManagedReferenceFieldInjectionInterceptorFactory.java:112) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ManagedReferenceFieldInjectionInterceptorFactory$ManagedReferenceFieldInjectionInterceptor.processInvocation(ManagedReferenceFieldInjectionInterceptorFactory.java:112) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        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.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:226) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:331) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ejb3.tx.SingletonLifecycleCMTTxInterceptor.processInvocation(SingletonLifecycleCMTTxInterceptor.java:57) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        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.1.3.Final-redhat-4]
        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.1.3.Final-redhat-4]
        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.BasicComponent.constructComponentInstance(BasicComponent.java:161) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ee.component.BasicComponent.createInstance(BasicComponent.java:85) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ejb3.component.singleton.SingletonComponent.getComponentInstance(SingletonComponent.java:118) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ejb3.component.singleton.SingletonComponent.start(SingletonComponent.java:133) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        at org.jboss.as.ee.component.ComponentStartService$1.run(ComponentStartService.java:54) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09-icedtea]
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09-icedtea]
        at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09-icedtea]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_09-icedtea]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_09-icedtea]
        at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09-icedtea]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "storage_pool_iso_map" violates foreign key constraint "fk_storage_domain_pool_map_storage_pool"
  Detail: Key (storage_pool_id)=(eb59b1a9-37d2-427f-a158-bd2cdc7b11bc) is not present in table "storage_pool".
  Where: SQL statement "INSERT INTO storage_pool_iso_map(storage_id, storage_pool_id, status, owner) VALUES( $1 ,  $2 ,  $3 ,  $4 )"
PL/pgSQL function "insertstorage_pool_iso_map" line 2 at SQL statement
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2062)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1795)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:479)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:367)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:360)
        at org.jboss.jca.adapters.jdbc.CachedPreparedStatement.execute(CachedPreparedStatement.java:297)
        at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.execute(WrappedPreparedStatement.java:404)
        at org.springframework.jdbc.core.JdbcTemplate$6.doInCallableStatement(JdbcTemplate.java:1066) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate$6.doInCallableStatement(JdbcTemplate.java:1) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:1014) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        ... 56 more

2013-03-13 18:41:51,133 INFO  [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 38) Running compensation on startup for Command : org.ovirt.engine.core.bll.storage.RemoveStoragePoolCommand , Command Id : 076abb88-ead3-4a87-9d31-a534f41ad127

Comment 1 Haim 2013-03-13 17:08:37 UTC
Created attachment 709719 [details]
engine.log

Comment 2 Yair Zaslavsky 2013-03-13 17:34:02 UTC
Several issues -
a. I know that the upgrade script says "you have running tasks" - but its a lie. I already expressed my point of view, that if you have compensation entries, the upgrade script should not call them "tasks" at the info presented to the user.
b. The async task tool (of 3.1.x) does not contain a way to eliminate these entries. However, a simple script or even direct SQL command of - "delete from bunsiness_entity_snapshots" will do the trick.
c. Since, AFAIK, there are no DB schema changes between two z-stream versions,
the compensation should have worked.
IMHO - something is wrong in the order the compensation entries got into db.

Comment 3 Eli Mesika 2013-03-14 12:34:09 UTC
(In reply to comment #2)
> Several issues -
> a. I know that the upgrade script says "you have running tasks" - but its a
> lie. I already expressed my point of view, that if you have compensation
> entries, the upgrade script should not call them "tasks" at the info
> presented to the user.
> b. The async task tool (of 3.1.x) does not contain a way to eliminate these
> entries. However, a simple script or even direct SQL command of - "delete
> from bunsiness_entity_snapshots" will do the trick.
> c. Since, AFAIK, there are no DB schema changes between two z-stream
> versions,
> the compensation should have worked.
> IMHO - something is wrong in the order the compensation entries got into db.

taskcleaner has a -C flag that cleans compensation , is installer using that

Comment 4 Alex Lourie 2013-03-14 12:57:57 UTC
(In reply to comment #3)

> taskcleaner has a -C flag that cleans compensation , is installer using that

Yes.

Comment 5 Eli Mesika 2013-03-17 15:37:11 UTC
fixed in commit : 9f99df6

Comment 8 Elad 2013-04-07 07:39:21 UTC
Checked on RHEVM-3.2 - SF13:
rhevm-backend-3.2.0-10.18.beta2.el6ev.noarch


upgraded rhevm from SF12 to SF13, had task left in async tasks table(remove to DC)

Comment 9 Itamar Heim 2013-06-11 08:28:26 UTC
3.2 has been released

Comment 10 Itamar Heim 2013-06-11 08:28:30 UTC
3.2 has been released

Comment 11 Itamar Heim 2013-06-11 08:31:36 UTC
3.2 has been released