Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Hibernate Envers listeners fail because EntityManager is closed too early when using JPA/JTA/Hibernate 5.2.8/Envers [SPR-15334] #19897

Closed
spring-projects-issues opened this issue Mar 9, 2017 · 8 comments
Assignees
Labels
in: data status: invalid

Comments

@spring-projects-issues
Copy link
Collaborator

@spring-projects-issues spring-projects-issues commented Mar 9, 2017

Allan Jones opened SPR-15334 and commented

My environment:

Using spring with JPA + JTA and Hibernate 5.2.8.Final + Envers

The problem is that Springframework ORM (JPA subpackage) closes the entity manager too early (During ```java
triggerBeforeCompletion(status)


When the Hibernate envers listeners are triggered (during ```java
doCommit(status)
``` step), the entity manager is already closed.


Exception in thread "main" org.springframework.transaction.UnexpectedRollbackException: JTA transaction unexpectedly rolled back (maybe due to a timeout); nested exception is javax.transaction.RollbackException: The transaction was set to rollback only
at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1026)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
at com.myapp.services.MyService.reproduceIssue(MyService.java:40)
at com.myapp.App.main(App.java:12)
Caused by: javax.transaction.RollbackException: The transaction was set to rollback only
at com.atomikos.icatch.jta.TransactionImp.rethrowAsJtaRollbackException(TransactionImp.java:66)
at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:207)
at com.atomikos.icatch.jta.TransactionManagerImp.commit(TransactionManagerImp.java:433)
at com.atomikos.icatch.jta.J2eeUserTransaction.commit(J2eeUserTransaction.java:94)
at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1023)
... 4 more
Caused by: java.lang.IllegalStateException: Session/EntityManager is closed
at org.hibernate.internal.AbstractSharedSessionContract.checkOpen(AbstractSharedSessionContract.java:332)
at org.hibernate.engine.spi.SharedSessionContractImplementor.checkOpen(SharedSessionContractImplementor.java:126)
at org.hibernate.internal.SessionImpl.guessEntityName(SessionImpl.java:2228)
at org.hibernate.envers.event.spi.BaseEnversEventListener.addCollectionChangeWorkUnit(BaseEnversEventListener.java:107)
at org.hibernate.envers.event.spi.BaseEnversEventListener.generateBidirectionalCollectionChangeWorkUnits(BaseEnversEventListener.java:76)
at org.hibernate.envers.event.spi.EnversPostInsertEventListenerImpl.onPostInsert(EnversPostInsertEventListenerImpl.java:49)
at org.hibernate.action.internal.EntityInsertAction.postInsert(EntityInsertAction.java:164)
at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:131)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:586)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:460)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1428)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:484)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3190)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2404)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:467)
at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:320)
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.atomikos.icatch.jta.Sync2Sync.beforeCompletion(Sync2Sync.java:50)
at com.atomikos.icatch.imp.TransactionStateHandler.notifyBeforeCompletion(TransactionStateHandler.java:261)
at com.atomikos.icatch.imp.TransactionStateHandler.commit(TransactionStateHandler.java:236)
at com.atomikos.icatch.imp.CompositeTransactionImp.doCommit(CompositeTransactionImp.java:288)
at com.atomikos.icatch.imp.CompositeTransactionImp.commit(CompositeTransactionImp.java:337)
at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:191)
... 7 more



WIth some analysis I found that
TransactionalEntityManagerSynchronization (org.springframework.orm.jpa.EntityManagerFactoryUtils) closes the entityManager too early and there's no way to configure or change the following:

```java 
org.springframework.transaction.support.ResourceHolderSynchronization<H, K>

	protected boolean shouldReleaseBeforeCompletion() {
		return true;
	}

In hibernate 4.x there's no problem because the EntityManager and hibernate Session are two different instances and closing the entity manager won't always close the hibernate session. In hibernate 5.2.x they are the same instance.

I created a small setup where I can reproduce the issue. Please find it attached.
Main class: ```java
com.myapp.App


Affects: 4.3.7

Attachments:

Issue Links:

  • #18899 Support for Hibernate ORM 5.2
@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 13, 2017

Juergen Hoeller commented

Hibernate 5.2's SessionImpl.close() implementation has a special code path for JPA close calls, triggering exactly such a 'logical' close as we need it here. Any idea why this isn't working in your scenario? Could you please debug SessionImpl.close() to see what exactly happens (isJpaBootstrap, isTransactionInProgress, etc)?

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 14, 2017

Allan Jones commented

That can be easily reproduced with MyApp.zip project.

getSessionFactory().getSessionFactoryOptions().isJpaBootstrap()
``` returns true

```java
if ( discardOnClose || !isTransactionInProgress( false ) )
``` returns false

And the following part closes the session
```java 
			else {
				//Otherwise, session auto-close will be enabled by shouldAutoCloseSession().
				waitingForAutoClose = true;
				closed = true;
			}

since it has closed=true

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 14, 2017

Juergen Hoeller commented

OK, so technically the EntityManager is in auto-close mode as expected: not actually closing/invalidating any underlying resources, just marking the user-level handle as closed. This is exactly what we mean to trigger there because we are indeed done from a user operation perspective, and it's generally good practice to trigger a logical close before transaction commit in a JTA environment. Some application servers would even log warnings if managed resources don't get closed: Regular application code has to close resources before it returns, after all, so before the managed transaction commit phase. We're following the same pattern.

However, it seems that Hibernate Envers relies on the user handle still being open at commit time. That's arguably a design flaw: Envers is an internal extension which should operate independently from the user-level state of the Session handle. The guessEntityName method that Envers uses there isn't on the regular Session contract even but rather on the internal SharedSessionContractImplementor; that guessEntityName implementation shouldn't call checkOpen() since it isn't meant to be called by user code begin with. That's where the actual bug is from my perspective.

I suppose this worked against Hibernate up until 5.1 since the EntityManager decorator had its separate user-level close flag, not propagating it to the underlying Session. Hibernate 5.2 introduced this regression with its EntityManager / Session merge where all of a sudden internal calls to Session get validated against EntityManager-level user state.

All in all, please report this to Hibernate itself as well: In JPA, 'open' vs 'closed' is just a user-level indication, with the session entirely able to participate in the transaction commit phase still... just falling over its own feet by validating checkOpen calls on internal delegate methods there. Literally, all it takes is to drop the checkOpen() call from the SessionImpl.guessEntityName implementation (and possibly from other such internal delegate methods).

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 14, 2017

Allan Jones commented

I have created an issue in hibernate:
https://hibernate.atlassian.net/browse/HHH-11570

-I also facing another issue with Infinispan and there was this reply:-
-bq. The root cause is the order in which synchronizations are invoked in Atomikos. While JBossTM (which we use for both development & testing) invokes Synchronization#beforeCompletion in the same order as they were registered (#afterCompletion is invoked in the opposite order), Atomikos holds these in a stack and #beforeCompletion is invoked in the opposite order. As Hibernate registers itself during #openSession and Infinispan during #persist, Infinispan starts committing the transaction, an then Hibernate calls flush on the dirty entity - but at this point Infinispan does not allow to modify the transaction in commit process anymore.-
-https://issues.jboss.org/browse/ISPN-7595?focusedCommentId=13376550&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-13376550-

-Probably this might be related to that as well.-

Just replaced atomikos with Jboss Narayana and the same issue. They are not related

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 14, 2017

Juergen Hoeller commented

To the best of my understanding, this will indeed happen with any transaction manager. Also, it will not just happen with Spring but rather with any use of "application-managed" EntityManagers, i.e. with any application obtaining an EntityManager via EntityManagerFactory.createEntityManager() and then closing it via EntityManager.close() before it returns, with a JTA transaction commit triggered afterwards.

Within an active transaction, EntityManager.close() should be seen as a user-level indication of "I'm done with this handle", not having any implications on further internal use of the underlying Session facilities. This was the case with Hibernate up until 5.1, so it really looks like an unintended side effect of Hibernate 5.2's EntityManager/Session combo. Fortunately, it seems easy enough to fix through removing that assertion on Hibernate's internal delegates.

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 17, 2017

Andrei Ivanov commented

I see Hibernate released version 5.2.9 with HHH-11570 marked as fixed for it.

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 17, 2017

Juergen Hoeller commented

Marking it as invalid from Spring's side, assuming that our interaction remains correct and that the fix in Hibernate ORM 5.2.9 makes it work properly again.

@spring-projects-issues
Copy link
Collaborator Author

@spring-projects-issues spring-projects-issues commented Mar 20, 2017

Allan Jones commented

Thanks for the support.
Hibernate 5.2.9.Final fixed that issue, but it still fails when executing other Hibernate Envers listeners: https://hibernate.atlassian.net/browse/HHH-11570?focusedCommentId=92012&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-92012

But that's still a hibernate issue and not a spring issue.

@spring-projects-issues spring-projects-issues added type: bug status: invalid in: data labels Jan 11, 2019
@spring-projects-issues spring-projects-issues removed the type: bug label Jan 12, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: data status: invalid
Projects
None yet
Development

No branches or pull requests

2 participants