Hibernate Envers throws "the owning Session was closed" with Spring 5.1 and Hibernate ORM 5.3

Hello, 

We have an existing fully functional web solution in production since a couple of years. The key technologies are

Wildfly 10.1.0
Java 8
Spring 4.3.3
Hibernate 5.0.10 ( JPA engine in Wildfly 10.1.0 )
Envers 5.0.10

So the upgrade was to go to the setting

Wildfly 15.0
Java 11
Spring 5.1.3
Hibernate 5.3.7 ( JPA engine in Wildfly 15 )

Just doing this switch and som minor code changes (very minor) all is well, the application starts and I can login with no problem, i.e. I can read and map to entities with no problem. But on update to database under @ Transaction we have a very big issue that seems to be related to Hibernate ( see bug HHH-11570 same discussion ). The update seems to go well, it is when Hibernate Envers needs to start an audited entity that the session is closed an Hibernate throws an exception.
Please let me know if this is a bug? I tried to deploy the original non upgraded Java 8 war to the server but the problem is exactly the same so this is a good argument to say that the problem is Hibernate or Wildfly. I really need to upgrade the system. Let me know if you need more stacktrace, code or configuration.

And some configurations of Spring are

@ Configuration
@ EnableTransactionManagement
@ EnableJpaRepositories(basePackages="se.eaktiebok.repository")
public class JpaConfiguration {
@ Bean
public DataSource dataSource() throws NamingException{
	Context ctx = new InitialContext();
	DataSource dataSource = (DataSource)ctx.lookup("java:/eaktiebok");
	return dataSource;
}	

@ Bean
public PlatformTransactionManager transactionManager() throws NamingException{
	JtaTransactionManager tm = new JtaTransactionManager();
	tm.afterPropertiesSet();
	return tm;
}

@ Bean
public SharedEntityManagerBean entityManager() throws NamingException{
	SharedEntityManagerBean entityManager = new SharedEntityManagerBean();
	entityManager.setEntityManagerFactory(this.entityManagerFactory());
	return entityManager;
} 	

@ Bean 
EntityManagerFactory entityManagerFactory() throws IllegalArgumentException, NamingException{
    org.springframework.jndi.JndiObjectFactoryBean jndiObjectFactoryBean = new org.springframework.jndi.JndiObjectFactoryBean();
    jndiObjectFactoryBean.setJndiName("java:app/JPADBFactory");
    jndiObjectFactoryBean.setLookupOnStartup(true);
    jndiObjectFactoryBean.setExpectedType(EntityManagerFactory.class);
    jndiObjectFactoryBean.afterPropertiesSet(); 
    return (EntityManagerFactory) jndiObjectFactoryBean.getObject();
}

}

AuthUser entity

@ Entity
@ Table(name=“auth_user”)
@ Audited(withModifiedFlag=true)
public class AuthUser implements Serializable {
private static final long serialVersionUID = 1L;

@ Id
@ GeneratedValue(strategy = GenerationType.IDENTITY)
private Integer iduser;

....

@ ManyToOne(fetch=FetchType.LAZY)
@ JoinColumn(name="idclient", insertable=false, updatable = false)
private AuthClient authClient;

}

The wildfly datasource is defined in standalone.xml as

            <datasource jndi-name="java:/eaktiebok" pool-name="eaktiebok">
                <connection-url>jdbc:mysql://xxxxxxxxxxxxxxxxx:3306/eaktiebokdump?useSSL=false</connection-url>
                <driver-class>com.mysql.jdbc.Driver</driver-class>
                <driver>mysql</driver>
                <security>
                    <user-name>xxxxxxx</user-name>
                    <password>xxxxxxx</password>
                </security>
                <validation>
                    <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker"/>
                    <background-validation>true</background-validation>
                    <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>
                </validation>
            </datasource>

persistence.xml

<?xml version="1.0" encoding="UTF-8" ?>

<persistence-unit name="jpaEabMysqlUnit" transaction-type="JTA">
    <provider>org.hibernate.ejb.HibernatePersistence</provider>
    <jta-data-source>java:/eaktiebok</jta-data-source>
    <properties>
    	<property name="hibernate.jdbc.use_streams_for_binary" value="true"/>
    	<property name="hibernate.dialect" value="org.hibernate.dialect.MySQL5InnoDBDialect"/>
     	<property name="hibernate.temp.use_jdbc_metadata_defaults" value="false"/>
     	<property name="org.hibernate.envers.store_data_at_delete" value="false"/>
    	<property name="hibernate.generate_statistics" value="false"/>
     	<property name="jboss.entity.manager.jndi.name" value="java:app/JPADB"/>
     	<property name="jboss.entity.manager.factory.jndi.name" value="java:app/JPADBFactory"/>
    </properties>
</persistence-unit>

Stacktrace

21:12:38,943 DEBUG [org.springframework.transaction.jta.JtaTransactionManager.handleExistingTransaction] (default task-3) Participating in existing transaction
21:12:38,943 DEBUG [org.springframework.data.repository.core.support.TransactionalRepositoryProxyPostProcessor$CustomAnnotationTransactionAttributeSource.getTransactionAttribute] (default task-3) Adding transactional method ‘save’ with attribute: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
21:12:38,944 DEBUG [org.springframework.transaction.jta.JtaTransactionManager.handleExistingTransaction] (default task-3) Participating in existing transaction
21:12:38,948 DEBUG [org.springframework.orm.jpa.EntityManagerFactoryUtils.closeEntityManager] (default task-3) Closing JPA EntityManager
21:12:38,949 DEBUG [org.springframework.transaction.jta.JtaTransactionManager.processCommit] (default task-3) Initiating transaction commit
21:12:38,996 ERROR [org.hibernate.internal.ExceptionMapperStandardImpl.mapManagedFlushFailure] (default task-3) HHH000346: Error during managed flush [org.hibernate.LazyInitializationException: could not initialize proxy [se.eaktiebok.jpa.auth.AuthClient#1] - the owning Session was closed]
21:12:39,003 WARN [com.arjuna.ats.arjuna.beforeCompletion] (default task-3) ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffffc0a801b7:4c9ef3ea:5c23e08f:66, org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization@e778004 >: javax.persistence.PersistenceException: org.hibernate.LazyInitializationException: could not initialize proxy [se.eaktiebok.jpa.auth.AuthClient#1] - the owning Session was closed
at org.hibernate@5.3.7.Final//org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)

Caused by: org.hibernate.LazyInitializationException: could not initialize proxy [se.eaktiebok.jpa.auth.AuthClient#1] - the owning Session was closed
at org.hibernate@5.3.7.Final//org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:172)
at org.hibernate@5.3.7.Final//org.hibernate.proxy.AbstractLazyInitializer.getIdentifier(AbstractLazyInitializer.java:89)
at org.hibernate@5.3.7.Final//org.hibernate.envers.internal.entities.mapper.id.SingleIdMapper.mapToMapFromEntity(SingleIdMapper.java:125)
at org.hibernate@5.3.7.Final//org.hibernate.envers.internal.entities.mapper.relation.ToOneIdMapper.mapToMapFromEntity(ToOneIdMapper.java:55)
at org.hibernate@5.3.7.Final//org.hibernate.envers.internal.entities.mapper.MultiPropertyMapper.map(MultiPropertyMapper.java:90)
at org.hibernate@5.3.7.Final//org.hibernate.envers.internal.synchronization.work.ModWorkUnit.(ModWorkUnit.java:43)
at org.hibernate@5.3.7.Final//org.hibernate.envers.event.spi.EnversPostUpdateEventListenerImpl.onPostUpdate(EnversPostUpdateEventListenerImpl.java:46)
at org.hibernate@5.3.7.Final//org.hibernate.action.internal.EntityUpdateAction.postUpdate(EntityUpdateAction.java:268)
at org.hibernate@5.3.7.Final//org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:215)
at org.hibernate@5.3.7.Final//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
at org.hibernate@5.3.7.Final//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
at org.hibernate@5.3.7.Final//org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
at org.hibernate@5.3.7.Final//org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate@5.3.7.Final//org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454)
… 131 morePreformatted text

Mixing Spring and Wildfly so that you use Hibernate is a very unusual combination.

Try to debug and see why the Session got closed. It could be an incompatibility issue that might have to be addressed in either Spring, Wildfly or Hibernate.

Why would it be strange to mix Wildfly, Spring and Hibernate? Wildfly is an JEE server that out of the box uses Hibernate to implement the JPA module. Spring is a Java framework that has no limitations regarding Wildfly.

I have done a lot of debugging but I can’t see the problem. But the issue is very similar to the one that I indicated in my description that was a bug in Hibernate. Spring closes the entityManager but as described in that bug that should still work according to JPA specifications.

Yes, it is unusual because Spring is a Java EE alternative and you can simply run a Spring application in a we container like Tomcat. Also a Java EE application has CDI so you don’t need Spring DI for that either.

If Spring closes the Session but Hibernate still needs it, then it’s a Spring issue. You need to open a Jira issue in Spring for this.

Only if you can replicate it with this test case template, while emulating a valud JPA interaction that Spring does , it would be a Hibernate issue.

As I mentioned there exists a Jira ticket HHH-11570 in Hibernate where the discussion has already been done regarding Spring closing the entity manager and that this is according to specification and recognized as a HIbernate problem. This ticket is very similar to my problem so I would like to avoid opening an issue with Spring to just get back to Hibernate again.

Also, debugging in Wildfly 10.1.0 I can see that Spring closes the entityManager in precisely the same point, and when Hibernate checks later in SessionImpl the session does not result as closed, I don’t know why because a lot happens in between.

I will try to see if I can create a test case template, the problem for me is that it is complex, I have Wildfly, Spring and Hibernate involved and I don’t know where the issue is. I have JUnit tests for all of this with integration tests, using Spring and Hibernate, but there for some reason the problem does not exist, but this excludes the JEE container.

Both HHH-11570 and HHH-11580 are already Fixed and available since 5.2.10.

So, this must be a new issue. Go to HHH-11570 and get the test case that was attached to the issue, and try to modify it to replicate your current issue. Afterward, you should open a new Jira issue and attach your replicating test case.

Yes I know it is closed, I just wanted to point out that it is very similar, with entitymanager being closed. I will see if I can reproduce this somehow not using Wildfly.

So I can’t put a resource on this, we don’t have time. I’ll leave a trace of how we resolved it. For whom might see this conversation, after some investigation the problem is probably with Hibernate. We tried to deploy our original application with only upgrading the Wildfly and it solved nothing. The workaround for us was to annotate all @ManyToOne Lazy entities with @NotAudited. Other discussion I found on Spring Stackoverflow with other people with similar upgrade problem, they also opted for a workaround.

I don’t believe that just because it worked a certain way in a past version and the newer version deviates from that and some issue arises necessarily implies the new approach is the one which is flawed. There have been several situations in the past where Hibernate has been extremely lenient and allowed corner cases behavior that eventually proved problematic or contradictory to new features that we’ve had to adapt over the years. I’m not saying that this is one of those yet, but its certainly a possibility.

That said I also don’t believe simply marking an audited field as @NotAudited to bypass the issue is the right approach, we need to get to the root of the problem and fix it; that ends up being the best not only for you but for everyone who is experiencing the problem.

What I need to understand is why Spring believes the underlying Session should be closed when the actual transaction has not yet been committed and the final status of the transaction determined. The events which fire that deal with processing the Envers audit history all happen as a part of the same transaction immediately before the commit is applied. I’m unclear why it would be seen as “per spec” to close the Session otherwise without knowing the status of the transaction here.

On the surface my gut reaction is to agree with Vlad here in that it sounds much like a container issue, whether that is Spring or WildFly here in this case. But I think rather than point fingers, lets try to find the culprit and then work to find a resolution here. You’ve provided some good detail in your first post, is there no way that could be packaged up in a quick test template for us?

I’m not pointing any fingers, I’m just trying to draw some conclusion without knowing the root cause. But deploying the solution as I did on Wildfly 10, means that I did not update Spring, the only difference then would be the Wildfly container or the Hibernate version, since Hibernate is the JPA engine in Wildfly. I noticed that someone had the same problem on Wildfly 14, so it’s not strictly linked, it would seem to the latest Wildfly. My problem right now is that my team are very busy, so for me to really resolve this, and believe me, of course I want to resolve, I need time.

I will try to find the time to create a Template that would reproduce this problem, but since that would need to be done excluding Wildfly and Spring, I don’t know how to easily in a short time span do this. If I find the time, or the client would pay me to get a better product I will be back.

I understand its time consuming, but I also think its best to get these test cases from you so we don’t make any false assumptions about enivronment/configuration/usage.

Another idea which may be faster for your team could be to consider a small app deployment on WildFly that doesn’t use Spring but rather the native Java EE features supplied by WildFly to accomplish the same with a replicated Hibernate scenario.

If you experience the same problem without Spring but solely WildFly/Hibernate, that may be much easier for us to take that as-is and run with it since at least those two components are more within our wheelhouse of experience than Spring.

If you don’t experience the same problems when Spring isn’t in the mix, then its a pretty safe bet whats the root-cause then its a matter of understanding why Spring is doing what it does when its its involved.

Btw, what exactly is the transaction doing with the audited entity when the error happens? I’d like to confirm that nothing unsupported is happening here at least with how the entity/audited entity is being managed in the transaction itself by your code.

Just a quick update @mickelson.

I was able to successfully reproduce the issue using only Hibernate. It seems the trick to getting the exception to happen was to use hibernate.jpa.compliance.proxy=true. This setting is false by default when using Hibernate in a stand-alone environment but I’m not sure what WildFly may set this to.

It is defintely something we should fix but perhaps as a workaround until we get a bugfix in place for this, could you try setting hibernate.jpa.compliance.proxy=false in your configuration and see if that resolves your problem?

I’d appreciate if you could let me know if it does.

I can verify that I added this property in the persistence.xml and it works fine, this seems to be a better workaround thank you. Will you create some Jira where I can follow up this issue?

Good work guys, and thanks for the support.

@mickelson, I have created JIRA HHH-13191 and there is already some pending review work with pull requests to address the problem in the next 5.4.1 release.