7 Replies Latest reply on Nov 3, 2015 5:53 AM by trepel

Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

trepel Oct 27, 2015 7:23 AM

Hi,

I have noticed that if you are using native hibernate 5 (no JPA) + container managed JTA transactions, your app very soon become unable to acquire database connection from pool. It seems that database connections are not released and returned back to pool properly. I created simple reproducer [1] that is based on WildFly 10 greeter example [2] for this.

If you downgrade to hibernate 4.3.11.Final, everything works as expected. To reproduce the error it is better to decrease the datasource pool size. For this you can add following lines to datasource element in standalone.xml:

                    <pool>
                        <min-pool-size>1</min-pool-size>
                        <max-pool-size>5</max-pool-size>
                    </pool>

After deploying the reproducer [1] and perform at least 6 operations that require database access the following exception occurs:

11:56:01,099 ERROR [io.undertow.request] (default task-7) UT005023: Exception handling request to /hibernate-greeter/greet.jsf: javax.servlet.ServletException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
  at javax.faces.webapp.FacesServlet.service(FacesServlet.java:671)
  at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:86)
  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:72)
  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:284)
  at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:263)
  at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
  at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:174)
  at io.undertow.server.Connectors.executeRootHandler(Connectors.java:198)
  at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:784)
  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:745)
Caused by: javax.faces.el.EvaluationException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
  at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:101)
  at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:102)
  at javax.faces.component.UICommand.broadcast(UICommand.java:315)
  at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:790)
  at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1282)
  at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81)
  at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
  at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:198)
  at javax.faces.webapp.FacesServlet.service(FacesServlet.java:658)
  ... 27 more
Caused by: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
  at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
  at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
  at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
  at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:90)
  at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:112)
  at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
  at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
  at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
  at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
  at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1928)
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1897)
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1875)
  at org.hibernate.loader.Loader.doQuery(Loader.java:919)
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:336)
  at org.hibernate.loader.Loader.doList(Loader.java:2611)
  at org.hibernate.loader.Loader.doList(Loader.java:2594)
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2423)
  at org.hibernate.loader.Loader.list(Loader.java:2418)
  at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
  at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:371)
  at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:220)
  at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1268)
  at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
  at org.hibernate.internal.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:955)
  at org.jboss.as.quickstarts.greeter.domain.NativeHibernateUserDao.getForUsername(NativeHibernateUserDao.java:21)
  at org.jboss.as.quickstarts.greeter.domain.NativeHibernateUserDao$Proxy$_$$_WeldSubclass.getForUsername$$super(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:497)
  at org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
  at org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
  at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:117)
  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:497)
  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 org.jboss.as.quickstarts.greeter.domain.NativeHibernateUserDao$Proxy$_$$_WeldSubclass.getForUsername(Unknown Source)
  at org.jboss.as.quickstarts.greeter.web.GreetController.greet(GreetController.java:38)
  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:497)
  at com.sun.el.util.ReflectionUtil.invokeMethod(ReflectionUtil.java:181)
  at com.sun.el.parser.AstValue.invoke(AstValue.java:289)
  at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:304)
  at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:40)
  at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50)
  at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:40)
  at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50)
  at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105)
  at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:87)
  ... 35 more
Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/ExampleDS
  at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:170)
  at org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:73)
  at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
  at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:382)
  at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:87)
  ... 92 more
Caused by: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/ExampleDS
  at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:670)
  at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:430)
  at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:761)
  at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:162)
  ... 96 more
Caused by: javax.resource.ResourceException: IJ000655: No managed connections available within configured blocking timeout (30000 [ms])
  at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:570)
  at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:717)
  at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:614)
  at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:603)
  ... 99 more

If you have an idea what could go wrong or what I might have misconfigured, please let me know.

Thnak you,

Tomas

[1] trepel/hibernate-greeter · GitHub

[2] quickstart/greeter at 10.x · wildfly/quickstart · GitHub

1. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

smarlow Oct 27, 2015 1:08 PM (in response to trepel)

What happens if you specify org.hibernate.engine.transaction.jta.platform.internal.JBossAppServerJtaPlatform at https://github.com/trepel/hibernate-greeter/blob/master/src/main/java/org/jboss/as/quickstarts/greeter/domain/HibernateUtil.java#L29?

So that hibernate.transaction.factory_class is set to "org.hibernate.engine.transaction.jta.platform.internal.JBossAppServerJtaPlatform" instead of "org.hibernate.transaction.CMTTransactionFactory".
Actions
2. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

smarlow Oct 28, 2015 8:41 AM (in response to smarlow)

In terms of what you did wrong, your referencing the org.hibernate.transaction.CMTTransactionFactory class which is not in Hibernate 5.
Actions
3. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

trepel Nov 2, 2015 7:24 AM (in response to smarlow)

Hi smarlow,
sorry for late response and thanks for finding time for this. I haven't noticed that CMTTransactionFactory has been removed in Hibernate 5. I tried your proposal and it didn't help. In fact I tried a lot of combinations of values of current_session_context_class, transaction.jta.platform and transaction.factory_class properties, but with no luck. I think having hibernate.current_session_context_class set to "jta" and hibernate.transaction.jta.platform set to "JBossAS" should be sufficient. I just commented out the transaction.factory_class property because it seems to me that it is not used in Hibernate 5 at all.

I updated the reproducer to use Hibernate 5.0.3.Final and I tried WildFly 10.0.0.CR4, the behaviour remains the same.
Actions
4. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

smarlow Nov 2, 2015 9:59 AM (in response to trepel)

That was my first guess as to what the cause is. From looking at the exception call stack, it looks like there is an active transaction but its not clear if Hibernate knows that.

IronJacamar debug logging might help to show what is leaking the connections. You could try enabling "<cached-connection-manager debug="true"/>" for your datasource. Or you could also try enabling the IronJacamar leak detector pool.
Actions
5. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

smarlow Nov 2, 2015 10:48 AM (in response to trepel)

Your configuration looks correct now, just a matter of finding the connection pool leak.

Regarding my last response, the cached-connection-manager setting is part of the JCA subsystem configuration (not part of the datasource). Open your wildfly/standalone/configuration/standalone.xml and change the:

cached-connection-manager/>

To:

<cached-connection-manager debug="true"/>
Actions
6. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

smarlow Nov 2, 2015 11:55 AM (in response to smarlow)

Also, you can try setting hibernate.transaction.factory_class to org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorBuilderImpl (see Hibernate dev mailing list discussion [1]). Also created HHH-10248 to map org.hibernate.transaction.CMTTransactionFactory to org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorBuilderImpl.

Hopefully, either the above DEBUG logging for finding connection leaks or specifying JtaTransactionCoordinatorBuilderImpl will help.

Scott

[1] http://lists.jboss.org/pipermail/hibernate-dev/2015-November/013625.html
[2] https://hibernate.atlassian.net/browse/HHH-10248
1 of 1 people found this helpful
Actions
7. Re: Native Hibernate 5 + JTA don't work in WildFly 10.0.0.CR3

trepel Nov 3, 2015 5:53 AM (in response to smarlow)

Thank you very much smarlow,

after reading the migration guide you pointed me to it became clear. What worked for me was to use hibernate.transaction.coordinator_class property instead of hibernate.transaction.factory_class. The value can be either fully qualified name ("org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorBuilderImpl") or just short-name ("jta").

I updated the reproducer accordingly.
Thanks again!
Actions

Go to original post