[jboss-jira] [JBoss JIRA] (WFLY-10962) WFLY14: set-tx-query-timeout broken on xa-datasource
Petr H (JIRA)
issues at jboss.org
Fri Aug 31 10:06:00 EDT 2018
[ https://issues.jboss.org/browse/WFLY-10962?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Petr H updated WFLY-10962:
--------------------------
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:
{noformat}
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 at 782ae3d8[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 3dabbda5 connection handles=1 lastReturned=1535718358200 lastValidated=1535718345234 lastCheckedOut=1535718358759 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl at 36ab279f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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 at 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
{noformat}
Followed with tons of:
{noformat}
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 at 1be6d5f7[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 5829c2e1 connection handles=1 lastReturned=1535718360457 lastValidated=1535718334651 lastCheckedOut=1535718360501 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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 at 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 at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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
{noformat}
(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 at 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.
was:
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:
{noformat}
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 at 782ae3d8[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 3dabbda5 connection handles=1 lastReturned=1535718358200 lastValidated=1535718345234 lastCheckedOut=1535718358759 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=udebsXA] xaResource=XAResourceWrapperImpl at 36ab279f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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/udebsXA] txSync=TransactionSynchronization at 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-11.0.0.Final/modules,/opt/wildfly-11.0.0.Final/modules/system/layers/base,/opt/BSCPraha/GEMINI/jboss-modules))]
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
{noformat}
Followed with tons of:
{noformat}
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 at 1be6d5f7[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 5829c2e1 connection handles=1 lastReturned=1535718360457 lastValidated=1535718334651 lastCheckedOut=1535718360501 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=udebsXA] xaResource=XAResourceWrapperImpl at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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/udebsXA] txSync=TransactionSynchronization at 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/udebsXA > (XAResourceWrapperImpl at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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/udebsXA]) 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
{noformat}
(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 at 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.
> WFLY14: set-tx-query-timeout broken on xa-datasource
> ----------------------------------------------------
>
> Key: WFLY-10962
> URL: https://issues.jboss.org/browse/WFLY-10962
> Project: WildFly
> Issue Type: Bug
> Components: JCA
> Affects Versions: 14.0.0.Final
> Environment: wildfly-14.0.0.Final
> jdk1.8.0_172
> CentOS Linux release 7.4.1708
> Reporter: Petr H
> Assignee: Stefano Maestri
>
> 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:
> {noformat}
> 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 at 782ae3d8[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 3dabbda5 connection handles=1 lastReturned=1535718358200 lastValidated=1535718345234 lastCheckedOut=1535718358759 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl at 36ab279f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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 at 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
> {noformat}
> Followed with tons of:
> {noformat}
> 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 at 1be6d5f7[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 5829c2e1 connection handles=1 lastReturned=1535718360457 lastValidated=1535718334651 lastCheckedOut=1535718360501 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 7f74fa31 mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 7c23cc82[pool=dsName] xaResource=XAResourceWrapperImpl at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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 at 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 at 39069b2f[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection at 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
> {noformat}
> (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 at 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.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
More information about the jboss-jira
mailing list