I am currently facing an issue when I fire an CDI event through a Hibernate lifecycle listener, and defer the notification until the transaction has succeeded using @Observe(during = ...). This logic works fine in some cases, but there seem some exceptions to the rule. This seems to be when the persistence event was called from a @Transactional method: my commit succeeds but the observer is never notified.
After debugging the issue I found out that for a successful transaction (i.e. no error being thrown, changes are persisted in the DB), I still entered the the the AFTER_FAILURE observer rather than the AFTER_SUCCESS observer. So somehow I am looking at a new transaction that will fail, however, silently. I only found the below stack trace by bubbling up the stack and find the exception.
Based on the stack trace we see a couple of things going on:
- All the way down below we leave our method, the TransactionalInterceptor commits the active transaction
- This causes entities to flush
- This triggers one of my lifecycle listeners
- The CDI event is fired in one lifecycle listener
- CDI figures out that the transaction is
IN_PROGRESS, where my event requiresAFTER_SUCCESS, so the notification is deferred. - Weld fails to add the synchronisation
registerSynchronizationinWeldTransactionServices, and fails with the stack trace below.
I am running in a JTA environment with container managed transactions. It seems Weld is not always able to call registerSynchronization and that in some cases other synchronisations have already been added to the transaction. It could be that there is something wrong with my setup, but it seems to me that this use of transactional observers is exactly what it is ment for. So I think this is a bug in either Arjuna or Weld, but I am not sure where exactly to start looking. Any advise is very much appreciated!
10:00:29,142 ERROR [java.lang.RuntimeException] (default task-3) java.lang.IllegalStateException: ARJUNA016082: Synchronizations are not allowed! Transaction status isActionStatus.RUNNING: java.lang.RuntimeException: java.lang.IllegalStateException: ARJUNA016082: Synchronizations are not allowed! Transaction status isActionStatus.RUNNING
at org.jboss.as.weld.services.bootstrap.WeldTransactionServices.registerSynchronization(WeldTransactionServices.java:98)
at org.jboss.weld.event.TransactionalObserverNotifier.deferNotification(TransactionalObserverNotifier.java:63)
at org.jboss.weld.event.TransactionalObserverNotifier.notifyTransactionObservers(TransactionalObserverNotifier.java:83)
at org.jboss.weld.event.ObserverNotifier.notify(ObserverNotifier.java:292)
at org.jboss.weld.event.ObserverNotifier.fireEvent(ObserverNotifier.java:160)
at org.jboss.weld.event.ObserverNotifier.fireEvent(ObserverNotifier.java:142)
at org.jboss.weld.manager.BeanManagerImpl.fireEvent(BeanManagerImpl.java:673)
at org.jboss.weld.util.ForwardingBeanManager.fireEvent(ForwardingBeanManager.java:101)
at com.pallasathenagroup.cdi.HibernateLifeCycleListener.onPostInsert(HibernateLifeCycleListener.java:42)
at org.hibernate.action.internal.EntityIdentityInsertAction.postInsert(EntityIdentityInsertAction.java:156)
at org.hibernate.action.internal.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:102)
at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:626)
at org.hibernate.engine.spi.ActionQueue.addResolvedEntityInsertAction(ActionQueue.java:280)
at org.hibernate.engine.spi.ActionQueue.addInsertAction(ActionQueue.java:261)
at org.hibernate.engine.spi.ActionQueue.addAction(ActionQueue.java:306)
at org.hibernate.event.internal.AbstractSaveEventListener.addInsertAction(AbstractSaveEventListener.java:318)
at org.hibernate.event.internal.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:275)
at org.hibernate.event.internal.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:182)
at org.hibernate.event.internal.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:113)
at org.hibernate.jpa.event.internal.core.JpaPersistEventListener.saveWithGeneratedId(JpaPersistEventListener.java:67)
at org.hibernate.event.internal.DefaultPersistEventListener.entityIsTransient(DefaultPersistEventListener.java:189)
at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:132)
at org.hibernate.internal.SessionImpl.firePersistOnFlush(SessionImpl.java:842)
at org.hibernate.internal.SessionImpl.persistOnFlush(SessionImpl.java:835)
at org.hibernate.engine.spi.CascadingActions$8.cascade(CascadingActions.java:341)
at org.hibernate.engine.internal.Cascade.cascadeToOne(Cascade.java:467)
at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:392)
at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:193)
at org.hibernate.engine.internal.Cascade.cascadeCollectionElements(Cascade.java:500)
at org.hibernate.engine.internal.Cascade.cascadeCollection(Cascade.java:432)
at org.hibernate.engine.internal.Cascade.cascadeAssociation(Cascade.java:395)
at org.hibernate.engine.internal.Cascade.cascadeProperty(Cascade.java:193)
at org.hibernate.engine.internal.Cascade.cascade(Cascade.java:126)
at org.hibernate.event.internal.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:150)
at org.hibernate.event.internal.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:141)
at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:74)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:38)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3207)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2413)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:330)
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 org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:116)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:368)
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:1200)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:175)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:121)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:53)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:76)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
at com.pallasathenagroup.iris.impl.ScopeResourceImpl$Proxy$_$$_WeldSubclass.addScopeCosts(Unknown Source)
at com.pallasathenagroup.iris.impl.ScopeResourceImpl$Proxy$_$$_WeldClientProxy.addScopeCosts(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139)
at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:402)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209)
at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:221)
at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: ARJUNA016082: Synchronizations are not allowed! Transaction status isActionStatus.RUNNING
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronizationImple(TransactionImple.java:401)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronization(TransactionImple.java:377)
at org.jboss.as.weld.services.bootstrap.WeldTransactionServices.registerSynchronization(WeldTransactionServices.java:96)
... 121 more
There are two types of synchronization that can be registered with a transaction, session and interposed. Session synchronization beforeCompletion callbacks are called before interposed ones.
Note that interposed synchronizations were introduced to provide an ordering guarantee for synchronizations.
The JTA specification does not specify how session synchronizations are ordered and the Narayana transaction manager chooses to order them according to an internal scheme and if an attempt is made to add a synchronization that should appear before a one that has already run then it refuses the registration. This appears to be the issue in your stacktrace. Would it be possible for Weld to register an interposed synchronization for the notification.