Blocked Threads with MultipleHiLoPerTableGenerator

uwesinha · **Joined:** Mon Mar 30, 2015 3:17 pm **Posts:** 1

After moving our production environment to a high performace data center, we're facing an issue which at first glance looks similar to a very old bug, HHH-1739.

Our webapp records some user actions -- e.g. opening a session, starting a search -- to a database table LogAktion. After starting (or restarting) the webapp runs smoothly for some hours until it suddenly answers all HTTP requests with a 503 error. We traced the error down by taking a series of thread dumps all of which showed that one thread holding a MultipleHiLoPerTableGenerator blocks an increasing number of other threads. All these threads, both blocking and blocked, try to insert a new entity into LogAktion. Ids are generated using the TABLE strategy. Since opening a session is THE most common user action in a webapp, there are a lot of LogAktion entities to be written.

The stacktrace of a blocked thread looks like this (company names munged by me):

Code:

"ajp-bio-8009-exec-8116" daemon prio=10 tid=0x00007f7de4131310 nid=0x51b3 waiting for monitor entry [0x00007f7d8d9d0000]
   java.lang.Thread.State: BLOCKED (on object monitor)
   at org.hibernate.id.MultipleHiLoPerTableGenerator.generate(MultipleHiLoPerTableGenerator.java:145)
   - waiting to lock <0x00000003e609e198> (a org.hibernate.id.MultipleHiLoPerTableGenerator)
   at org.hibernate.event.internal.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:117)
   at org.hibernate.ejb.event.EJB3PersistEventListener.saveWithGeneratedId(EJB3PersistEventListener.java:78)
   at org.hibernate.event.internal.DefaultPersistEventListener.entityIsTransient(DefaultPersistEventListener.java:208)
   at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:151)
   at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:78)
   at org.hibernate.internal.SessionImpl.firePersist(SessionImpl.java:852)
   at org.hibernate.internal.SessionImpl.persist(SessionImpl.java:826)
   at org.hibernate.internal.SessionImpl.persist(SessionImpl.java:830)
   at org.hibernate.ejb.AbstractEntityManagerImpl.persist(AbstractEntityManagerImpl.java:875)
   at sun.reflect.GeneratedMethodAccessor98.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:606)
   at org.springframework.orm.jpa.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler.invoke(ExtendedEntityManagerCreator.java:366)
   at com.sun.proxy.$Proxy49.persist(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor98.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:606)
   at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:241)
   at com.sun.proxy.$Proxy49.persist(Unknown Source)
   at de.**OUR_COMPANY**.framework.jpa.AbstractGenericDAO.persist(AbstractGenericDAO.java:167)
   at de.**OUR_COMPANY**.framework.jpa.AbstractGenericDAO$$FastClassBySpringCGLIB$$c8abe486.invoke( )
   at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
   at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:700)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:633)
   at de.**CUSTOMER**.**PROJECT**.entity.dao.LogAktionDAO$$EnhancerBySpringCGLIB$$e0c5bdc9.persist( )

We use Hibernate ORM 4.2.0 on JDK 7u79. The underlying DBMS is MySQL 5.6.25. For the webapp we use Wicket 1.5.x with Spring 3.2.x.

This combo worked fine on our old (slower) production machine. After switching to new hardware we kept getting these errors -- until we resorted to disable recording of user actions completely. The latter seems to indicate that the source of the problem actually is the generation of ids for the LogAktion table. Our next step will be changing the Id generation strategy from TABLE to IDENTITY for that LogAktion table only. Nevertheless we (and what is more, our customer) would like to be sure we will not get these errors again.

Could it be we hit that old bug, or is there anything else we might have done wrong?

Any hints are appreciated.

EDIT: Of course, I saw Per Olesens workaround for this problem. Nevertheless I would like to get rid of this without having to fiddle with allocationSize while still keeping the TABLE generation strategy. For some entities it's important to have human-readable (i.e not too high) Ids.

Thanks in advance,

Uwe

vlad · **Posted:** Sat Dec 05, 2015 5:11 am

The MultipleHiLoPerTableGenerator is deprecated nowadays and the org.hibernate.id.enhanced.TableGenerator can offer better scalability due to configurable optimizers: pooled, pooled-lo.

Using the IDENTITY generator will fix the locking issue, but will disable JDBC batching, so you need to take that into consideration too.

sanne.grinovero · **Posted:** Tue Dec 08, 2015 8:44 am

Hi Uwe,
if you have a nice modern high end server you will probably want to update Hibernate to the very latest 5.0.5.Final : we also keep getting new toys and there has been a lot of internal rework in Hibernate 5 to put the new kinds of hardware to better use: much less contention, and an amazing amount of less temporary objects allocated which really help to scale without hitting issues with too much garbage.

We backported some of those improvements (what was possible to backport without breaking the API contract) to later updates of Hibernate 4.2.x, so if you can't upgrade to Hibernate 5, then you should at least consider getting to Hibernate 4.2.22.Final

And while this IdGenerator is deprecated, please let us know of other code paths which need optimization as we're very keen on that. Patches very welcome as usual as we're a small team, but even if you can just point out problematic code points that's very helpful too.

Thanks