Details
-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
14.0.0.Final
-
None
-
Workaround Exists
-
Description
In order to test the WFLY-10621 issue I migrated the domain configuration from WFLY 11 to WFLY 14 and started the domain and process controllers which was successfull.
However after starting the 1st app server instance I encountered the following warnings and consequently the application dependent on that particular datasource wasn't working properly:
2018-08-31 14:26:00,606 WARN [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (myScheduler-1) IJ000305: Connection error occured: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@782ae3d8[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@3dabbda5 connection handles=1 lastReturned=1535718358200 lastValidated=1535718345234 lastCheckedOut=1535718358759 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl@36ab279f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@3dabbda5 pad=false overrideRmValue=false productName=Oracle productVersion=Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics and Real Application Testing options jndiName=java:/jdbc/dsName] txSync=TransactionSynchronization@1944287995{tx=Local transaction (delegate=TransactionImple < ac, BasicAction: 0:ffff0a020b45:-4d9ac9e1:5b8933a1:10 status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider) wasTrackByTx=true enlisted=true cancel=false}]: javax.resource.spi.ResourceAdapterInternalException: Unexpected error at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.broadcastConnectionError(BaseWrapperManagedConnection.java:664) at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.connectionError(BaseWrapperManagedConnection.java:630) at org.jboss.jca.adapters.jdbc.WrappedConnection.checkException(WrappedConnection.java:1969) at org.jboss.jca.adapters.jdbc.WrappedStatement.checkException(WrappedStatement.java:1436) at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:541) ... Caused by: java.lang.NoClassDefFoundError: org/wildfly/transaction/client/ContextTransactionManager at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getTimeLeftBeforeTransactionTimeout(TxConnectionManagerImpl.java:392) at org.jboss.jca.adapters.jdbc.WrapperDataSource.getTimeLeftBeforeTransactionTimeout(WrapperDataSource.java:201) at org.jboss.jca.adapters.jdbc.WrappedConnection.checkConfiguredQueryTimeout(WrappedConnection.java:2043) at org.jboss.jca.adapters.jdbc.WrappedStatement.checkConfiguredQueryTimeout(WrappedStatement.java:1456) at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:531) ... 41 more Caused by: java.lang.ClassNotFoundException: org.wildfly.transaction.client.ContextTransactionManager from [Module "org.jboss.ironjacamar.impl" version 1.4.11.Final from local module loader @5e5792a0 (finder: local module finder @26653222 (roots: /opt/wildfly-14.0.0.Final/modules,/opt/wildfly-14.0.0.Final/modules/system/layers/base))] at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:255) at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:410) at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:398) at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:116) ... 46 more
Followed with tons of:
2018-08-31 14:26:00,635 WARN [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 85) IJ000305: Connection error occured: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@1be6d5f7[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5829c2e1 connection handles=1 lastReturned=1535718360457 lastValidated=1535718334651 lastCheckedOut=1535718360501 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl@39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5829c2e1 pad=false overrideRmValue=false productName=Oracle productVersion=Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics and Real Application Testing options jndiName=java:/jdbc/dsName] txSync=TransactionSynchronization@1776960750{tx=Local transaction (delegate=TransactionImple < ac, BasicAction: 0:ffff0a020b45:-4d9ac9e1:5b8933a1:1a status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider) wasTrackByTx=true enlisted=true cancel=false}]: javax.resource.spi.ResourceAdapterInternalException: Unexpected error at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.broadcastConnectionError(BaseWrapperManagedConnection.java:664) at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.connectionError(BaseWrapperManagedConnection.java:630) at org.jboss.jca.adapters.jdbc.WrappedConnection.checkException(WrappedConnection.java:1969) at org.jboss.jca.adapters.jdbc.WrappedStatement.checkException(WrappedStatement.java:1436) at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:509) ... Caused by: java.lang.NoClassDefFoundError: org/wildfly/transaction/client/ContextTransactionManager at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getTimeLeftBeforeTransactionTimeout(TxConnectionManagerImpl.java:392) at org.jboss.jca.adapters.jdbc.WrapperDataSource.getTimeLeftBeforeTransactionTimeout(WrapperDataSource.java:201) at org.jboss.jca.adapters.jdbc.WrappedConnection.checkConfiguredQueryTimeout(WrappedConnection.java:2043) at org.jboss.jca.adapters.jdbc.WrappedStatement.checkConfiguredQueryTimeout(WrappedStatement.java:1456) at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:498) ... 62 more 2018-08-31 14:26:00,775 WARN [com.arjuna.ats.jta] (ServerService Thread Pool -- 85) ARJUNA016045: attempted rollback of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a020b45:-4d9ac9e1:5b8933a1:1a, node_name=1, branch_uid=0:ffff0a020b45:-4d9ac9e1:5b8933a1:1e, subordinatenodename=null, eis_name=java:/jdbc/dsName > (XAResourceWrapperImpl@39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5829c2e1 pad=false overrideRmValue=false productName=Oracle productVersion=Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics and Real Application Testing options jndiName=java:/jdbc/dsName]) failed with exception code XAException.XAER_RMFAIL: oracle.jdbc.xa.OracleXAException at oracle.jdbc.xa.OracleXAResource.checkError(OracleXAResource.java:1229) at oracle.jdbc.xa.client.OracleXAResource.rollback(OracleXAResource.java:979) at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:357) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196) at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:362) at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3023) at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3002) at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1674) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:124) at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1370) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:134) at org.wildfly.transaction.client.LocalTransaction.rollbackAndDissociate(LocalTransaction.java:111) at org.wildfly.transaction.client.ContextTransactionManager.rollback(ContextTransactionManager.java:83) at org.wildfly.transaction.client.LocalUserTransaction.rollback(LocalUserTransaction.java:58) ... Caused by: java.sql.SQLRecoverableException: Closed Connection at oracle.jdbc.driver.PhysicalConnection.needLine(PhysicalConnection.java:4220) at oracle.jdbc.driver.T4CXAResource.doTransaction(T4CXAResource.java:756) at oracle.jdbc.driver.T4CXAResource.doRollback(T4CXAResource.java:635) at oracle.jdbc.xa.client.OracleXAResource.rollback(OracleXAResource.java:974) ... 56 more
(basically on every attempt to use that datasource)
Based on the stack trace I deduced this is related to the set-tx-query-timeout=true setting on that datasource (which is xa-datasource) so I removed that for now and the problem disappeared.
Notes:
1. Non-XA datasources don't seem to be affected, but they still could be - see the next point.
2. In this particular case this xa-datasource is attempted to be used during the server startup, before the instance is fully up, e.g. before the WFLYSRV0212: Resuming server and WFLYSRV0026: WildFly Full 14.0.0.Final (WildFly Core 6.0.1.Final) started events (for example managed scheduled executors throw (EE-ManagedScheduledExecutorService-default-Thread-1) WFLYEE0110: Failed to run scheduled task: java.lang.IllegalStateException: WFLYEE0111: Cannot run scheduled task javax.enterprise.concurrent.ManagedExecutors$ManagedRunnable@12caf21c as container is suspended at this point). This fact might be somehow related to the issue. However since the 1st failure occurrence the datasource doesn't recover from that.
3. About a month ago I tested the same config (with set-tx-query-timeout in place) at WFLY 13 and there was no such issue, only WFLY 14 is affected.