com.mysql.jdbc.jdbc2.optional.MysqlXAException: XAER_DUPID: The XID already exists

[mattforshaw]

Hi,

I'm receiving the following exception during a distributed transaction pointed at a MySQL 5 db.

I have four JBoss instances running on a single server, each with their respective port offsets and unique jboss.node.name values. One server hosts a jsp which remote invokes EJBs on the other three servers.

I have also added a unique node-identifier to the core-environment tag in the transactions subsystem in standalone-full.xml.

The exception is thrown by the second service attempting to access the database, and the full trace is as follows...

{quote}

15:00:47,096 WARN  [com.arjuna.ats.jtax] (EJB default - 10) ARJUNA024046: TransactionImple.enlistResource - XAResource.start returned XA error ARJUNA016099: Unknown error code:0 for transaction < 131072, 29, 37, 0000000000-1-11014145-31880-5080-121-14140005149, 292929292929292929292828394343342647109-21109-92154329292980782929292929292929 >: com.mysql.jdbc.jdbc2.optional.MysqlXAException: XAER_DUPID: The XID already exists

at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:604)

at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:583)

at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.start(MysqlXAConnection.java:523)

at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.start(XAManagedConnection.java:259)

at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.start(XAResourceWrapperImpl.java:188)

at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.enlistResource(TransactionImple.java:727)

at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.enlistResource(TransactionImple.java:498)

at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.enlist(TxConnectionListener.java:587)

at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:264)

at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:467)

at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:599)

at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:467)

at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:139)

at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:278) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:297) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:169) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.extractPhysicalConnection(ConnectionProxyHandler.java:82) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:138) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at $Proxy24.prepareStatement(Unknown Source)     at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:147) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:166) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:145) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1720) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQuery(Loader.java:828) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:289) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.loadEntity(Loader.java:2042) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:82) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:72) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3715) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:439) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:420) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:204) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:251) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:148) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1046) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.access$1900(SessionImpl.java:173) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2389) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.get(SessionImpl.java:942) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:801) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:776) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.jboss.as.jpa.container.AbstractEntityManager.find(AbstractEntityManager.java:193) [jboss-as-jpa-7.1.2.Final.jar:7.1.2.Final]

at uk.ac.ncl.cs.itec.csc8104.modelsolution.beans.HotelBean.getRoomById(HotelBean.java:69) [serviceb.jar:]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [classes.jar:1.6.0_35]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [classes.jar:1.6.0_35]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [classes.jar:1.6.0_35]

at java.lang.reflect.Method.invoke(Method.java:597) [classes.jar:1.6.0_35]

at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]

at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:36) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) [jboss-as-jpa-7.1.2.Final.jar:7.1.2.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.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation-1.1.1.Final.jar:1.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.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:201) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:305) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:189) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:80) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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:43) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:299) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:67) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:199) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [classes.jar:1.6.0_35]

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [classes.jar:1.6.0_35]

at java.util.concurrent.FutureTask.run(FutureTask.java:138) [classes.jar:1.6.0_35]

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [classes.jar:1.6.0_35]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [classes.jar:1.6.0_35]

at java.lang.Thread.run(Thread.java:680) [classes.jar:1.6.0_35]

at org.jboss.threads.JBossThread.run(JBossThread.java:122)

15:00:47,149 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 10) SQL Error: 0, SQLState: null

15:00:47,150 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 10) javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@16d383a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d connection handles=0 lastUse=1351087247149 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3f8d48 pool internal context=SemaphoreArrayListManagedConnectionPool@14516d4[pool=MySqlDS_Pool] xaResource=XAResourceWrapperImpl@17e2705[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d pad=false overrideRmValue=false productName=MySQL productVersion=5.1.44 jndiName=java:jboss/datasources/MySqlDS] txSync=null]

15:00:47,157 INFO  [org.hibernate.event.internal.DefaultLoadEventListener] (EJB default - 10) HHH000327: Error performing load command : org.hibernate.exception.GenericJDBCException: Could not open connection

15:00:47,164 ERROR [org.jboss.as.ejb3.tx.CMTTxInterceptor] (EJB default - 10) javax.ejb.EJBTransactionRolledbackException: org.hibernate.exception.GenericJDBCException: Could not open connection

15:00:47,169 ERROR [org.jboss.as.ejb3.invocation] (EJB default - 10) JBAS014134: EJB Invocation failed on component HotelBean for method public abstract uk.ac.ncl.cs.itec.csc8104.modelsolution.entities.Room uk.ac.ncl.cs.itec.csc8104.modelsolution.beans.Hotel.getRoomById(java.lang.String) throws java.lang.Exception: javax.ejb.EJBTransactionRolledbackException: org.hibernate.exception.GenericJDBCException: Could not open connection

at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleInCallerTx(CMTTxInterceptor.java:138) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:203) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:305) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:189) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:80) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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:43) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.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.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:299) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:67) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:199) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [classes.jar:1.6.0_35]

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [classes.jar:1.6.0_35]

at java.util.concurrent.FutureTask.run(FutureTask.java:138) [classes.jar:1.6.0_35]

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [classes.jar:1.6.0_35]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [classes.jar:1.6.0_35]

at java.lang.Thread.run(Thread.java:680) [classes.jar:1.6.0_35]

at org.jboss.threads.JBossThread.run(JBossThread.java:122)

Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection

at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1365) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:822) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:776) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.jboss.as.jpa.container.AbstractEntityManager.find(AbstractEntityManager.java:193) [jboss-as-jpa-7.1.2.Final.jar:7.1.2.Final]

at uk.ac.ncl.cs.itec.csc8104.modelsolution.beans.HotelBean.getRoomById(HotelBean.java:69) [serviceb.jar:]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [classes.jar:1.6.0_35]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [classes.jar:1.6.0_35]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [classes.jar:1.6.0_35]

at java.lang.reflect.Method.invoke(Method.java:597) [classes.jar:1.6.0_35]

at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]

at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:36) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) [jboss-as-jpa-7.1.2.Final.jar:7.1.2.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.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation-1.1.1.Final.jar:1.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.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.1.2.Final.jar:7.1.2.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.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.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.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:201) [jboss-as-ejb3-7.1.2.Final.jar:7.1.2.Final]

... 29 more

Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection

at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:304) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:169) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.extractPhysicalConnection(ConnectionProxyHandler.java:82) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:138) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at $Proxy24.prepareStatement(Unknown Source)     at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:147) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:166) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:145) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1720) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQuery(Loader.java:828) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:289) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.Loader.loadEntity(Loader.java:2042) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:82) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:72) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3715) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:439) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:420) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:204) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:251) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:148) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1046) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.access$1900(SessionImpl.java:173) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2389) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.SessionImpl.get(SessionImpl.java:942) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:801) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

... 53 more

Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@16d383a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d connection handles=0 lastUse=1351087247149 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3f8d48 pool internal context=SemaphoreArrayListManagedConnectionPool@14516d4[pool=MySqlDS_Pool] xaResource=XAResourceWrapperImpl@17e2705[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d pad=false overrideRmValue=false productName=MySQL productVersion=5.1.44 jndiName=java:jboss/datasources/MySqlDS] txSync=null]

at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:147)

at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70) [hibernate-entitymanager-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:278) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:297) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]

... 79 more

Caused by: javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@16d383a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d connection handles=0 lastUse=1351087247149 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3f8d48 pool internal context=SemaphoreArrayListManagedConnectionPool@14516d4[pool=MySqlDS_Pool] xaResource=XAResourceWrapperImpl@17e2705[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@c9277d pad=false overrideRmValue=false productName=MySQL productVersion=5.1.44 jndiName=java:jboss/datasources/MySqlDS] txSync=null]

at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:604)

at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:467)

at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:139)

... 82 more

Caused by: javax.resource.ResourceException: IJ000461: Could not enlist in transaction on entering meta-aware object

at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:474)

at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:599)

... 84 more

Caused by: javax.transaction.SystemException: IJ000356: Failed to enlist: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < jca-subordinate, com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction@2d24810e >

at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.checkEnlisted(TxConnectionListener.java:552)

at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:282)

at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:467)

... 85 more

15:00:47,371 WARN  [com.arjuna.ats.jts] (RequestProcessor-5) ARJUNA022261: ServerTopLevelAction detected that the transaction was inactive

15:00:47,651 WARN  [com.arjuna.ats.jts] (RequestProcessor-5) ARJUNA022261: ServerTopLevelAction detected that the transaction was inactive

15:00:47,784 INFO  [uk.ac.ncl.cs.itec.csc8104.modelsolution.beans.UserManagerBean] (EJB default - 3) Returning all users.

15:00:47,809 WARN  [com.arjuna.ats.jts] (RequestProcessor-5) ARJUNA022261: ServerTopLevelAction detected that the transaction was inactive

15:00:48,413 INFO  [uk.ac.ncl.cs.itec.csc8104.modelsolution.beans.TravelManagerBean] (EJB default - 4) Getting all bookings.

15:00:48,437 WARN  [com.arjuna.ats.jts] (RequestProcessor-5) ARJUNA022261: ServerTopLevelAction detected that the transaction was inactive

{quote}

Googling for this particular exception hasn't brought up much, and it appears from the JTS quickstarts that no further configuration of the servers is typically required (beyond the changes to jacorb and adding the <jts/> tag).

Any advice you could offer would be greatly appreciated!

All the best,

Matt

[tomjenkinson]

Hi Matt,

Much appreciated for the log. Please can you attach your configuration file and confirm your startup command?

Tom

[mattforshaw]

Hi Tom,

Standalone-full.xml attached.

My startup commands are as follows:

Client: sh bin/standalone.sh -Djboss.node.name=one -c standalone-full.xml

Server A: sh bin/standalone.sh -Djboss.node.name=two -c standalone-full.xml -Djboss.socket.binding.port-offset=100

Server B: sh bin/standalone.sh -Djboss.node.name=three -c standalone-full.xml -Djboss.socket.binding.port-offset=200

Server C: sh bin/standalone.sh -Djboss.node.name=four -c standalone-full.xml -Djboss.socket.binding.port-offset=300

Thanks!

Matt

[jhalliday]

> I have also added a unique node-identifier to the core-environment tag in the transactions subsystem in standalone-full.xml.

Which means you can't use the same file for all the servers, since they would then share the 'unique' value. Use separate config files, each with a distinct value.

[tomjenkinson]

I *think* this would work for you assuming you always set jboss.node.name on the command line:

<core-environment node-identifier="${jboss.node.name}">

I haven't had chance to test that yet but give it a whirl and let us know how you get on.

[mattforshaw]

Good morning,

Sorry, I should have been clearer in my last message: attached was only one standalone-full.xml. Each server has its own JBoss installation directory with unique IDs set in each.

I'll test out passing the node name as the node-identifier today and let you know how I get on.

Thanks for all the quick responses!

All the best,

Matt

[tomjenkinson]

Hi Matt,

I just wondered if passing the node-identifier had helped?

Tom

[tomjenkinson]

Also, please can you confirm the version of AS7 you are using?

[tomjenkinson]

Also, this should be an xa-datasource I guess: datasource jta="true" jndi-name="java:/jboss/datasources/MySqlDS2"

[tomjenkinson]

I think you using AS 7.1.2.Final, right?

[tomjenkinson]

Also, I have confirmed for myself in the debugger that setting <core-environment node-identifier="${jboss.node.name}"> *will not work* the unexpanded value is passed to JBTM. Therefore you will will  need separate standalone config files for each server each with a specific node-identifier value in it.

[tomjenkinson]

Also, please post all four standalone-full.xml files, there is additional config such as the EJB remoting config I might need to see.

[paul.robinson]

Tom,

Matt's in China at the moment with limited email access. We are currently using AS 7.1.3 with ejb-client upgraded to 1.0.12.Final. However, I don't know if this was the build Matt was using when he last worked on this issue. I can try and reproduce on our current AS build and then reply to your questions.

Paul.

[mattforshaw]

Hi all,

Sorry for the delay getting in touch about this. I can confirm it was the AS 7.1.3 build with the upgraded ejb-client I used when testing for this.

I'll be on GMT+8 for the next week but I'll do my best to reply as soon as I can if there's anything else I can do to assist.

All the best,

Matt

[tomjenkinson]

Hi,

I have looked into this more now and can see that it appears JBTM expects the DUPID in certain JTS circumstances: https://anonsvn.jboss.org/repos/labs/labs/jbosstm/tags/JBOSSTS_4_16_4_Final/ArjunaJTS/jtax/classes/com/arjuna/ats/internal/jta/transaction/jts/TransactionImple.java

You can see on here the comment:

/*

* If another process has (or is about to) create the same

* transaction association then we will probably get a failure

* during start with XAER_DUPID. We know this must be due to

* another server, since we keep track of our own registrations.

* So, if this happens we create a new transaction branch and

* try again.

*

* To save time we could always just create branches by default.

*

* Is there a benefit to a zero branch?

*/

Also, if you look on that file for DUPID, you can see our protection already adds a special case for Oracle where we will retry the xa.start on XAER_RMERR, it looks like we need to add a second special case for MySQL this time to check for "e.errorcode == 0" and retry then as well.

If you want a patch to build and test, I have created a Jira and attached a patch to it: https://issues.jboss.org/browse/JBTM-1336, it should overlay fine on top of: https://svn.jboss.org/repos/labs/labs/jbosstm/tags/JBOSSTS_4_16_4_Final

Tom