DEV Community

Cover image for Resolving Concurrent Exceptions in Hibernate Logger
Michael Born
Michael Born

Posted on • Edited on • Originally published at michaelborn.me

Resolving Concurrent Exceptions in Hibernate Logger

Recently while working on a Hibernate ORM project, I ran into an interesting issue when an entity with relationships is saved inside a transaction.

transaction{ var myEntity = entityLoadByPK( "Person", theEntityID ); myEntity.setAddress( otherEntity ); myEntity.save(); // throws "ConcurrentModificationException" on transaction end. } 
Enter fullscreen mode Exit fullscreen mode

Note this is not a complete test case - simply an example of when the issue occurs.

When the transaction completes, Lucee tries to flush the entity modifications, but this fails with the following error:

lucee.runtime.exp.NativeException: java.util.ConcurrentModificationException at java.base/java.util.HashMap$HashIterator.nextNode(HashMap.java:1493) at java.base/java.util.HashMap$EntryIterator.next(HashMap.java:1526) at java.base/java.util.HashMap$EntryIterator.next(HashMap.java:1524) at org.hibernate.internal.util.EntityPrinter.toString(EntityPrinter.java:112) at org.hibernate.event.internal.AbstractFlushingEventListener.logFlushResults(AbstractFlushingEventListener.java:128) at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:104) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:93) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1362) at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1349) at org.lucee.extension.orm.hibernate.HibernateORMTransaction.end(HibernateORMTransaction.java:57) at lucee.runtime.orm.ORMConnection.setAutoCommit(ORMConnection.java:213) at lucee.runtime.orm.ORMDatasourceConnection.setAutoCommit(ORMDatasourceConnection.java:336) at lucee.runtime.db.DatasourceManagerImpl.end(DatasourceManagerImpl.java:350) at lucee.runtime.db.DatasourceManagerImpl.end(DatasourceManagerImpl.java:330) at lucee.runtime.tag.Transaction.doFinally(Transaction.java:160) 
Enter fullscreen mode Exit fullscreen mode

It turns out this issue is related to the Hibernate debug logger. In Lucee, Hibernate's log4j logger is set to a DEBUG level by default. That's fine, but it seems the logger actually mutates the logged entities during logging. Thus we get a concurrent modification exception.

To resolve this, all we have to do is de-escalate the logging level from DEBUG to WARN.

/** * Resolves Hibernate ConcurrentModificationException when flushing an entity save with one-to-many relationships. * * @see https://access.redhat.com/solutions/29774 */ var Logger = createObject( "java", "org.apache.log4j.Logger" ); var level = createObject( "java", "org.apache.log4j.Level" ); var log = Logger.getLogger( "org.hibernate" ); log.setLevel( level.WARN ); 
Enter fullscreen mode Exit fullscreen mode

This should be done in the Application.cfc before ORM initializes - say, just below the this.ormSettings{} configuration block.

All thanks to @jclausen for this awesome find and easy fix!

Top comments (0)