1 Reply Latest reply on Nov 27, 2012 3:40 AM by zemunk

    Datasource Pool usage -> more connections used than available (?)

    zemunk

      We are running Jboss AS 7.1 in cluster mode with a load balancer in front running an AJP connector. After one month withouth problems, we tried redeploying our application (only minor changes that should not affect its behaviour).

       

      In the admin console we saw the following statistic that we cannot explain:

      jboss_pool_usage.png

       

      Additionally we got the following error:

       

      18:28:35,228 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-4c70d77b:50ae3c02:131 in state  RUN
      18:28:35,229 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff7f000101:-4c70d77b:50ae3c02:131 invoked while multiple threads active within it.
      18:28:35,230 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000101:-4c70d77b:50ae3c02:131 aborting with 1 threads active!
      18:28:35,231 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff7f000101:-4c70d77b:50ae3c02:131
      18:36:05,096 WARN  [com.arjuna.ats.arjuna] (ajp--192.168.0.120-8009-1) ARJUNA012077: Abort called on already aborted atomic action 0:ffff7f000101:-4c70d77b:50ae3c02:131
      18:36:05,097 ERROR [org.jboss.ejb3.invocation] (ajp--192.168.0.120-8009-1) JBAS014134: EJB Invocation failed on component Statistikmgmt for method public void de.r_kom.intern.webservices.Statistikmgmt.persistUser(webshop_statistik.bean.entity.User): javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:115) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:95) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:232) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:304) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:190) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ejb3.security.AuthorizationInterceptor.processInvocation(AuthorizationInterceptor.java:106) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:76) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:32) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
                at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
                at org.jboss.as.webservices.invocation.AbstractInvocationHandlerEJB.invoke(AbstractInvocationHandlerEJB.java:112)
                at org.jboss.wsf.stack.cxf.JBossWSInvoker._invokeInternal(JBossWSInvoker.java:181)
                at org.jboss.wsf.stack.cxf.JBossWSInvoker.invoke(JBossWSInvoker.java:127)
                at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58) [cxf-rt-core-2.4.6.jar:2.4.6]
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_07]
                at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_07]
                at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_07]
                at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37) [cxf-rt-core-2.4.6.jar:2.4.6]
                at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:106) [cxf-rt-core-2.4.6.jar:2.4.6]
                at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:263) [cxf-api-2.4.6.jar:2.4.6]
                at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-rt-core-2.4.6.jar:2.4.6]
                at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:207) [cxf-rt-transports-http-2.4.6.jar:2.4.6]
                at org.jboss.wsf.stack.cxf.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:91)
                at org.jboss.wsf.stack.cxf.transport.ServletHelper.callRequestHandler(ServletHelper.java:169)
                at org.jboss.wsf.stack.cxf.CXFServletExt.invoke(CXFServletExt.java:87)
                at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:185) [cxf-rt-transports-http-2.4.6.jar:2.4.6]
                at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:108) [cxf-rt-transports-http-2.4.6.jar:2.4.6]
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]
                at org.jboss.wsf.stack.cxf.CXFServletExt.service(CXFServletExt.java:135)
                at org.jboss.wsf.spi.deployment.WSFServlet.service(WSFServlet.java:140) [jbossws-spi-2.0.3.GA.jar:2.0.3.GA]
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]
                at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329)
                at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248)
                at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275)
                at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161)
                at org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.event(JBossWebContext.java:67)
                at org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.invoke(JBossWebContext.java:48)
                at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489)
                at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153)
                at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155)
                at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
                at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
                at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368)
                at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505)
                at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:445)
                at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:930)
                at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_07]
      Caused by: javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!
                at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1155)
                at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
                at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                ... 57 more
      
      
      18:36:05,122 ERROR [org.jboss.as.webservices.invocation.InvocationHandlerEJB3] (ajp--192.168.0.120-8009-1) Method invocation failed with exception: Transaction rolled back: javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:115) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
              (...)
      Caused by: javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!
                at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1155)
                at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
                at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                ... 57 more
      
      
      18:36:05,145 WARNING [org.apache.cxf.phase.PhaseInterceptorChain] (ajp--192.168.0.120-8009-1) Application {http://webservices.intern.r_kom.de/}StatistikmgmtService#{http://webservices.intern.r_kom.de/}persistUser has thrown exception, unwinding now: org.apache.cxf.interceptor.Fault: Transaction rolled back
                at org.jboss.wsf.stack.cxf.JBossWSInvoker.createFault(JBossWSInvoker.java:246)
              (...)
      Caused by: javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:115) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                (...)
                ... 35 more
      Caused by: javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!
                at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1155)
                at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
                at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
                at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
                ... 57 more
      
      

       

      We get this for other webservices too, all of them are stateless and we don't use sticky AJP sessions.

      If we shut down one of the cluster nodes, the application runs like desired.

       

      What does it mean and how can there be more connections used than available? How is it related to the errors in the log?

        • 1. Re: Datasource Pool usage -> more connections used than available (?)
          zemunk

          We found the problem.

           

          The connection pool in jboss was too small and the database itself was also set to accept too few connections. Because of the sudden growth in the number of applications that accessed it, we forgot to readjust the numbers.

          The requests kept being queued until the timeout was reached and the error thrown.