Quarkus: Hibernate ORM - Unable to perform un-delete for instance Entity

Created on 16 Sep 2020 · 11Comments · Source: quarkusio/quarkus

Describe the bug

I am currently in the process of migrating another wildfly 10 (hibernate 5.0.10) application, which is already running in production, to quarkus.
The problem I am facing now does not happen in the wildfly 10 version of the app.

I run the following 2 transactions in my application:

Transaction 1:

find ExampleParentEntity with id 2
find ExampleParentEntity with id 4
create ExampleParentEntity with id 2
** this entity is associated to ExampleManyToOneEntity with id 3
Create Entity with id 4
** this entity is associated to ExampleManyToOneEntity with id 3

Transaction 2:

find ExampleParentEntity with id 2
find ExampleParentEntity with id 4
Copy values from ExampleParentEntity#4 to ExampleParentEntity#2
em.remove ExampleParentEntity#4
Search for ExampleManyToOneEntity#3 (em.find)

Transaction 1 runs fine, entities are created.
Transaction 2 causes the exception from below. The search causes entities to be flushed to the database.

Expected behavior
Transaction 2 runs without problems.

Actual behavior

1
1
2
2020-09-16 13:52:10,017 ERROR [org.hib.AssertionFailure] (executor-thread-1) HHH000099: an assertion failure occurred (this may indicate a bug in Hibernate, but is more likely due to unsafe use of the session): org.hibernate.AssertionFailure: Unable to perform un-delete for instance org.acme.ExampleChildEntity
2020-09-16 13:52:10,019 WARN  [com.arj.ats.arjuna] (executor-thread-1) ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffff0a28f887:f9fb:5f61fc69:8, org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@58bf60a1 >: org.hibernate
.AssertionFailure: Unable to perform un-delete for instance org.acme.ExampleChildEntity
        at org.hibernate.engine.spi.ActionQueue.unScheduleDeletion(ActionQueue.java:856)
        at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:134)
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:113)
        at org.hibernate.internal.SessionImpl.persistOnFlush(SessionImpl.java:766)
        at org.hibernate.engine.spi.CascadingActions$8.cascade(CascadingActions.java:341)
        at org.hibernate.engine.internal.Cascade.cascadeToOne(Cascade.java:492)
        at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:416)
        at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:218)
        at org.hibernate.engine.internal.Cascade.cascadeCollectionElements(Cascade.java:525)
        at org.hibernate.engine.internal.Cascade.cascadeCollection(Cascade.java:456)
        at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:419)
        at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:218)
        at org.hibernate.engine.internal.Cascade.cascade(Cascade.java:151)
        at org.hibernate.event.internal.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:158)
        at org.hibernate.event.internal.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:148)
        at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:81)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:102)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1363)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:454)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3213)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2381)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
        at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:355)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1287)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
        at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:97)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:311)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:164)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:100)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:35)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:53)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:26)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew_Bean.intercept(TransactionalInterceptorRequiresNew_Bean.zig:339)
        at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
        at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
        at org.acme.ExampleService_Subclass.runSchedule(ExampleService_Subclass.zig:290)
        at org.acme.ExampleService_ClientProxy.runSchedule(ExampleService_ClientProxy.zig:183)
        at org.acme.ExampleService_ScheduledInvoker_runSchedule_05c71edd8a96aefb5980964d2485321467821725.invokeBean(ExampleService_ScheduledInvoker_runSchedule_05c71edd8a96aefb5980964d2485321467821725.zig:45)
        at io.quarkus.arc.runtime.BeanInvoker.invoke(BeanInvoker.java:20)
        at io.quarkus.scheduler.runtime.SimpleScheduler$ScheduledTask$1.run(SimpleScheduler.java:226)
        at io.quarkus.runtime.CleanableExecutor$CleaningRunnable.run(CleanableExecutor.java:231)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
        at java.base/java.lang.Thread.run(Thread.java:834)
        at org.jboss.threads.JBossThread.run(JBossThread.java:479)

2020-09-16 13:52:10,022 ERROR [io.qua.sch.run.SimpleScheduler] (executor-thread-1) Error occured while executing task for trigger IntervalTrigger [id=1_org.acme.ExampleService_ScheduledInvoker_runSchedule_05c71edd8a96aefb5980964d2485321467821725, interval=1000]: io.quarkus.arc.ArcUndeclaredThrowableException: E
rror invoking subclass method
        at org.acme.ExampleService_Subclass.runSchedule(ExampleService_Subclass.zig:312)
        at org.acme.ExampleService_ClientProxy.runSchedule(ExampleService_ClientProxy.zig:183)
        at org.acme.ExampleService_ScheduledInvoker_runSchedule_05c71edd8a96aefb5980964d2485321467821725.invokeBean(ExampleService_ScheduledInvoker_runSchedule_05c71edd8a96aefb5980964d2485321467821725.zig:45)
        at io.quarkus.arc.runtime.BeanInvoker.invoke(BeanInvoker.java:20)
        at io.quarkus.scheduler.runtime.SimpleScheduler$ScheduledTask$1.run(SimpleScheduler.java:226)
        at io.quarkus.runtime.CleanableExecutor$CleaningRunnable.run(CleanableExecutor.java:231)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
        at java.base/java.lang.Thread.run(Thread.java:834)
        at org.jboss.threads.JBossThread.run(JBossThread.java:479)
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1299)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
        at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:97)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:311)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:164)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:100)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:35)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:53)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:26)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew_Bean.intercept(TransactionalInterceptorRequiresNew_Bean.zig:339)
        at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
        at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
        at org.acme.ExampleService_Subclass.runSchedule(ExampleService_Subclass.zig:290)
        ... 15 more
Caused by: org.hibernate.AssertionFailure: Unable to perform un-delete for instance org.acme.ExampleChildEntity
        at org.hibernate.engine.spi.ActionQueue.unScheduleDeletion(ActionQueue.java:856)
        at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:134)
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:113)
        at org.hibernate.internal.SessionImpl.persistOnFlush(SessionImpl.java:766)
        at org.hibernate.engine.spi.CascadingActions$8.cascade(CascadingActions.java:341)
        at org.hibernate.engine.internal.Cascade.cascadeToOne(Cascade.java:492)
        at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:416)
        at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:218)
        at org.hibernate.engine.internal.Cascade.cascadeCollectionElements(Cascade.java:525)
        at org.hibernate.engine.internal.Cascade.cascadeCollection(Cascade.java:456)
        at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:419)
        at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:218)
        at org.hibernate.engine.internal.Cascade.cascade(Cascade.java:151)
        at org.hibernate.event.internal.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:158)
        at org.hibernate.event.internal.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:148)
        at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:81)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:102)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1363)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:454)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3213)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2381)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
        at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:355)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1287)
        ... 28 more

To Reproduce
Steps to reproduce the behavior:

Download this reproducer project:
hibernate-lazy-one-to-one.zip
mvn clean compile quarkus:dev.
Look into the console output. The scheduler in ExampleService will cause the above mentioned Exception.

Configuration

quarkus.datasource.db-kind=h2
quarkus.datasource.username=sa
quarkus.datasource.jdbc.url=jdbc:h2:mem:test
quarkus.hibernate-orm.database.generation=drop-and-create

Environment (please complete the following information):

Output of uname -a or ver: MSYS_NT-10.0 NANB7NLNVP2 2.10.0(0.325/5/3) 2018-06-13 23:34 x86_64 Msys
Quarkus version or git rev: 1.8.0.Final
Build tool (ie. output of mvnw --version or gradlew --version):
Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: C:\eclipse\tools\apache-maven\bin..
Java version: 11.0.7, vendor: Azul Systems, Inc., runtime: C:\eclipse\tools\zulu11.39.15-ca-jdk11.0.7-win_x64
Default locale: de_DE, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

arehibernate-orm arepersistence kinbug triagwontfix

Source

Postremus

All 11 comments

/cc @gsmet, @Sanne

quarkusbot on 16 Sep 2020

Given it's an upgrade from Hibernate ORM 5.0, it might be a plain ORM issue. @Sanne @dreab8 would one of you have the time to check what's going on?

gsmet on 16 Sep 2020

@gsmet I'm going to go give a look at it;

dreab8 on 17 Sep 2020

@Postremus so @dreab8 took at a look at your issue and the problem is coming from the fact that all entities are bytecode enhanced in Quarkus so you can't use clone() as it will also clone some enhancement-specific fields that are specific to the given entity.

In this case, you should use a copy constructor that just copies the fields and not use clone(). I will add a warning to the documentation.

gsmet on 17 Sep 2020

Interesting point. We might want to enhance the clone() methods, to throw an explicit errror or do "the right thing", which I think would be to detach the object.