Database connection gets closed?

[andreas_w]

Hi,

we are using WildFly 9 RC1 on one of our servers. Sometimes we get the following exception. Usually after a deadlock was detected and the transaction is in rollback. But should be this the default behaviour or who is closing the connection here. If someone has an idea please let me know. And let me know to, if I should provide more information. For testing we are running another server which has the same configuration. There we never saw this kind of error. But there isn't that much load on it. Thanks in advance for your help

 WARN  [com.arjuna.ats.jta] (EJB default - 7) ARJUNA016045: attempted rollback of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff86770b07:-1d249b76:555afea0:53d7a,
 node_name=1, branch_uid=0:ffff86770b07:-1d249b76:555afea0:53d7d, subordinatenodename=null, eis_name=java:/jdbc_mydb > (XAResourceWrapperImpl@40d2d7e[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedCo
nnection@5fa55077 pad=false overrideRmValue=null productName=MySQL productVersion=5.5.40-0ubuntu0.12.04.1-log jndiName=java:/jdbc_mydb]) failed with exception code XAException.XAER_RMFAIL: com.mysql.jdbc
.jdbc2.optional.MysqlXAException: Undetermined error occurred in the underlying Connection - check your data for consistency
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:584)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:566)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.rollback(MysqlXAConnection.java:411)
        at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:346)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperStatImpl.rollback(XAResourceWrapperStatImpl.java:160)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:336)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2993)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2972)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1675)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:127)
        at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1282)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:114)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:93)
        at org.jboss.as.ejb3.tx.TimerCMTTxInterceptor.endTransaction(TimerCMTTxInterceptor.java:67)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634)
        at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:104)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:186)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:160)
        at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1236)
        at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:496)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
        at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)
        at com.mysql.jdbc.Util.getInstance(Util.java:360)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:935)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:924)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:870)
        at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1232)
        at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1225)
        at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2417)
        at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2401)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:558)
        ... 49 more

[jesper.pedersen]

Post your configuration...

[andreas_w]

Here is the configuration of our datasources:

<xa-datasource jndi-name="java:/jdbc_mydb" pool-name="mydb" enabled="true" use-java-context="true" statistics-enabled="true">
                    <xa-datasource-property name="ServerName">
                        ${Server}
                    </xa-datasource-property>
                    <xa-datasource-property name="DatabaseName">
                        mydb
                    </xa-datasource-property>
                    <xa-datasource-property name="PortNumber">
                        ${db.port}
                    </xa-datasource-property>
                    <driver>mysql</driver>
                    <xa-pool>
                        <min-pool-size>10</min-pool-size>
                        <initial-pool-size>10</initial-pool-size>
                        <max-pool-size>180</max-pool-size>
                    </xa-pool>
                    <security>
                        <user-name>${db.user}</user-name>
                        <password>${db.password}</password>
                    </security>
                    <validation>
                        <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker"/>
                        <validate-on-match>true</validate-on-match>
                        <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>
                    </validation>
                </xa-datasource>
                <xa-datasource jndi-name="java:/jdbc_mydb2" pool-name="mydb2" enabled="true" use-java-context="true" statistics-enabled="true">
                    <xa-datasource-property name="ServerName">
                        ${Server}
                    </xa-datasource-property>
                    <xa-datasource-property name="DatabaseName">
                        mydb2
                    </xa-datasource-property>
                    <xa-datasource-property name="PortNumber">
                        ${db.port}
                    </xa-datasource-property>
                    <driver>mysql</driver>
                    <xa-pool>
                        <min-pool-size>10</min-pool-size>
                        <initial-pool-size>10</initial-pool-size>
                        <max-pool-size>180</max-pool-size>
                    </xa-pool>
                    <security>
                        <user-name>${db.user}</user-name>
                        <password>${db.password}</password>
                    </security>
                    <validation>
                        <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker"/>
                        <validate-on-match>true</validate-on-match>
                        <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>
                    </validation>
                </xa-datasource>
                <xa-datasource jndi-name="java:/jdbc_mydb3" pool-name="mydb3" enabled="true" use-java-context="true" statistics-enabled="true">
                    <xa-datasource-property name="ServerName">
                        ${Server}
                    </xa-datasource-property>
                    <xa-datasource-property name="DatabaseName">
                        mydb3
                    </xa-datasource-property>
                    <xa-datasource-property name="PortNumber">
                        ${db.port}
                    </xa-datasource-property>
                    <driver>mysql</driver>
                    <xa-pool>
                        <min-pool-size>10</min-pool-size>
                        <initial-pool-size>10</initial-pool-size>
                        <max-pool-size>180</max-pool-size>
                    </xa-pool>
                    <security>
                        <user-name>${db.user}</user-name>
                        <password>${db.password}</password>
                    </security>
                    <validation>
                        <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker"/>
                        <validate-on-match>true</validate-on-match>
                        <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>
                    </validation>
                </xa-datasource>
                <drivers>
                    <driver name="h2" module="com.h2database.h2">
                        <xa-datasource-class>org.h2.jdbcx.JdbcDataSource</xa-datasource-class>
                    </driver>
                    <driver name="mysql" module="com.mysql">
                        <driver-class>com.mysql.jdbc.Driver</driver-class>
                        <xa-datasource-class>com.mysql.jdbc.jdbc2.optional.MysqlXADataSource</xa-datasource-class>
                    </driver>
                </drivers>

and here the transaction-subsystem

<subsystem xmlns="urn:jboss:domain:transactions:3.0">
            <core-environment>
                <process-id>
                    <uuid/>
                </process-id>
            </core-environment>
            <recovery-environment socket-binding="txn-recovery-environment" status-socket-binding="txn-status-manager"/>
            <coordinator-environment statistics-enabled="true" default-timeout="7200"/>
        </subsystem>

[jesper.pedersen]

Something has closed the connection, so you need to identify what. The rollback is done on the application thread, so that is a hint.

Maybe adding 'tracking="true"' can help (http://www.ironjacamar.org/doc/roadto12/txtracking.html), or a Byteman rule on the MySQL close() method...

Or try to look at TRACE on

• com.arjuna
• org.jboss.jca
• org.jboss.as.connector

[jesper.pedersen]

An alternative is to start by looking at the IronJacamar Tracer report (http://www.ironjacamar.org/doc/roadto12/tracer.html).

Enable TRACE for org.jboss.jca.core.tracer and do <tracer enable="true"/> in :jca:

Then use the tool from the IronJacamar distribution to process the log - Google Groups

[andreas_w]

Thanks for answers. I will take a look at these things. Here I have two other StackTraces. The first is a deadlock, the second this Exception that the connection is already closed. When I read the stacktrace correct, than this is the same connection. Furthermore this problem somehow occurs in an ejb timer task. Maybe this is somehow the problem? I mean the exceptions are occuring in a method which is triggered from an ejb-method annotated with @Timeout. Here are the stacktraces:

2015-05-20 07:45:57,185 WARN  [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 7) IJ000305: Connection error occured: org.jboss.jca.core.connectionmanager.listener.TxConn
ectionListener@425c1cb4[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2d608f75 connection handles=1 lastReturned=1432100744980 lastValidated=1432094372714 lastCheckedOu
t=1432100755960 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@e09ba98 mcp=SemaphoreArrayListManagedConnectionPool@4b38f041[pool=mydb] xaResource=XAResourceWrapperImpl@5b0
f42f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2d608f75 pad=false overrideRmValue=null productName=MySQL productVersion=5.5.40-0ubuntu0.12.04.1-log jndiName=java:/jdbc_mydb] txSync=nu
ll]: com.mysql.jdbc.jdbc2.optional.MysqlXAException: Undetermined error occurred in the underlying Connection - check your data for consistency
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:584)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:566)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.end(MysqlXAConnection.java:462)
        at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:295)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.end(XAResourceWrapperImpl.java:118)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperStatImpl.end(XAResourceWrapperStatImpl.java:96)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:318)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2993)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2972)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1675)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:127)
        at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1282)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:114)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:93)
        at org.jboss.as.ejb3.tx.TimerCMTTxInterceptor.endTransaction(TimerCMTTxInterceptor.java:67)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634)
        at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:104)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:186)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:160)
        at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1236)
        at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:496)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
        at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: java.sql.SQLException: XA_RBDEADLOCK: Transaction branch was rolled back: deadlock was detected
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:996)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3887)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3823)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2526)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2484)
        at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:848)
        at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:742)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:560)
        ... 49 more

2015-05-20 07:45:57,407 WARN  [com.arjuna.ats.jta] (EJB default - 7) ARJUNA016045: attempted rollback of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff86770b07:-1d249b76:555afea0:134e80, node_name=1, branch_uid=0:ffff86770b07:-1d249b76:555afea0:134e83, subordinatenodename=null, eis_name=java:/jdbc_mydb > (XAResourceWrapperImpl@5b0f42f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2d608f75 pad=false overrideRmValue=null productName=MySQL productVersion=5.5.40-0ubuntu0.12.04.1-log jndiName=java:/jdbc_mydb]) failed with exception code XAException.XAER_RMFAIL: com.mysql.jdbc.jdbc2.optional.MysqlXAException: Undetermined error occurred in the underlying Connection - check your data for consistency
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:584)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:566)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.rollback(MysqlXAConnection.java:411)
        at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:346)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperStatImpl.rollback(XAResourceWrapperStatImpl.java:160)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:336)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2993)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2972)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1675)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:127)
        at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1282)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:114)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:93)
        at org.jboss.as.ejb3.tx.TimerCMTTxInterceptor.endTransaction(TimerCMTTxInterceptor.java:67)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634)
        at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:104)
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:186)
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:160)
        at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1236)
        at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:496)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
        at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)
        at com.mysql.jdbc.Util.getInstance(Util.java:360)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:935)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:924)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:870)
        at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1232)
        at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1225)
        at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2417)
        at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2401)
        at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:558)
        ... 49 more

We sometimes also get this kind of stacktrace. But it's log-level is info. Can it be somehow connected to this problem?

07:57:45,048 INFO  [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-60) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@3c2386a7
  at org.jboss.jca.core.connectionmanager.ccm.CachedConnectionManagerImpl.unregisterConnection(CachedConnectionManagerImpl.java:414)
  at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.connectionClosed(TxConnectionListener.java:655)
  at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.returnHandle(BaseWrapperManagedConnection.java:631)
  at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.closeHandle(BaseWrapperManagedConnection.java:566)
  at org.jboss.jca.adapters.jdbc.WrappedConnection.returnConnection(WrappedConnection.java:289)
  at org.jboss.jca.adapters.jdbc.WrappedConnection.close(WrappedConnection.java:247)
  at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:464)
  at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:498)
  at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeConnection(DatabaseAccessor.java:487)
  at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeJTSConnection(DatasourceAccessor.java:176)
  at org.eclipse.persistence.sessions.server.ClientSession.releaseJTSConnection(ClientSession.java:115)
  at org.eclipse.persistence.transaction.AbstractSynchronizationListener.beforeCompletion(AbstractSynchronizationListener.java:171)
  at org.eclipse.persistence.transaction.JTASynchronizationListener.beforeCompletion(JTASynchronizationListener.java:68)
  at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:371)
  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
  at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
  at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)
  at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
  at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
  at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91)
  at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
  at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
  at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:44)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
  at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634)
  at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
  at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
  at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
  at org.jboss.as.ejb3.remote.LocalEjbReceiver.processInvocation(LocalEjbReceiver.java:261)
  at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:184)
at org.jboss.ejb.client.EJBObjectInterceptor.handleInvocation(EJBObjectInterceptor.java:58)
  at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
  at org.jboss.ejb.client.EJBHomeInterceptor.handleInvocation(EJBHomeInterceptor.java:83)
  at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
  at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:42)
  at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
  at org.jboss.ejb.client.ReceiverInterceptor.handleInvocation(ReceiverInterceptor.java:125)
  at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
  at org.jboss.ejb.client.EJBInvocationHandler.sendRequestWithPossibleRetries(EJBInvocationHandler.java:253)
  at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:198)
  at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:181)
  at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:144)
  at com.sun.proxy.$Proxy60.getObjectForCompanyId(Unknown Source)
  at com.mycompany.webapp.jsf.time.ObjectListBean.reload(ObjectListBean.java:233)
  at com.mycompany.webapp.jsf.time.ObjectListBean.timeRangeChanged(ObjectListBean.java:279)
  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:606)
  at com.sun.el.parser.AstValue.invoke(AstValue.java:292)
  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)
  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:646)
  at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:86)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:130)
  at org.apache.myfaces.webapp.filter.ExtensionsFilter.doFilter(ExtensionsFilter.java:147)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
  at jodd.servlet.filter.GzipFilter.doFilter(GzipFilter.java:70)
  at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
  at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
  at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:85)
  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.DisableCacheHandler.handleRequest(DisableCacheHandler.java:33)
  at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
  at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:51)
  at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
  at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
  at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:56)
  at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)
  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.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)
  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:274)
  at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:253)
  at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:80)
  at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:172)
  at io.undertow.server.Connectors.executeRootHandler(Connectors.java:199)
  at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:774)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
  at java.lang.Thread.run(Thread.java:745)

[smarlow]

Also enable TRACE on org.jboss.as.jpa, so you can understand the context of what JPA calls were made in the problem transaction.

[jesper.pedersen]

Use PostgreSQL and Hibernate

Maybe do <cached-connection-manager debug="true"/> in :jca: and look for unreleased connections in the log. Likewise add <track-statement>true</> to your datasources.

I expect an issue with EclipseLink, but start with the above and post the log from the Byteman MySQL close() dump.

It is a lifecycle of the connection management for sure.

[andreas_w]

Thanks for the answers. My only problem is that setting the log-levels to trace produce a lot of log messages. On the server where the problem occurs is a lot of load. I am not sure if it is a good idea to set the log levels there to trace. But I guess there will be no other way to track down the problem. Already tried to reproduce this problem on a testsystem with less load but looks like there this problem isn't existing. Furthermore I tried this trace-report on my development-system. Just to see what I can see there. I have to say, that I am not familiar with Byteman. Just looked it up in the Internet. But we were also thinking that it could be an issues regarding to eclipselink. The used version is pretty old. So maybe it would be a better idea to upgrade it first? @Jesper Pedersen If switching a database and a jpa-provider would be that easy... ;-)

[smarlow]

Would it be possible for you to eliminate the deadlock by changing the application to obtain the database locks in the same order?

[jesper.pedersen]

The IronJacamar tracer, and the Byteman script will have a low overhead, so that should be possible to install without losing too much performance.

But yeah, starting with the EclipseLink update and going from there could be an option...

[andreas_w]

okay, thanks for the infomration. The update of EclipseLink haven't changed anything.

@ScottMarlow We have a lot of stuff which is running concurrently, so we can't really avoid deadlocks.

[jesper.pedersen]

There shouldn't be any deadlocks if you don't do nuts stuff like "static java.sql.Connection" or pass connections between threads.

Time for the tracer and Byteman

[andreas_w]

yes, I will try out the tracer and Byteman. But it can take some time. As I said I am not familiar with Byteman, so it will take some time until I know how I can write the rule for the mysql.close(). I will let you know when I have more information.

And thanks again for your answers.

[andreas_w]

I tried to write a byteman rule. Can you take a look at it? As I said I am not familiar with Byteman. But looks like a great tool.

<br/>

<br/>

I tested it on a local installation of wildfly. Looks like it is working. The Thread.dumpStack() should show me how the close was triggered.

RULE MySQL-Close
INTERFACE java.sql.Connection
METHOD close
AT ENTRY
IF TRUE
DO traceln("JDBCTrace: Close-MYSQL=[" + $0 + "]"); Thread.dumpStack();
ENDRULE