Driver version
SQL Server JDBC Driver 7.0 & 8.2
SQL Server version
SQL Server AG 2017
Client Operating System
Windows Server 2016, version 10.0
JAVA/JVM version
IBM J9 VM
Table schema
Problem description
During a fail-over test for one of the product when using SQL server AG as back end, we found that there are few XA transactions in SQL Server DTC are in in-doubt state.
After analyzing the trace files, we found that the SQL Server JDBC driver was returning an XAException with an error code of XAER_RMERR on the XAResource.commit due to SQL Server AG fail-over. Websphere application server treats XAER_RMERR as a non-retriable condition as per the XA specification.
We tested with a diagnostic patch on Websphere application server to treat XAER_RMERR as a XAER_RMFAIL(which is retriable) and recreated the scenario.Due to the diagnostic patch Websphere retries the commits which are eventually successful and we no longer finding in-doubt transactions in SQL server DTC.
- Expected behaviour:
SQL Server Resource Adaptor(JDBC Driver) should return an XAException with a retriable error code such as XAER_RMFAIL in case fail-over of SQL Server AG from primary node to standby node while committing an XA Transaction.
- Actual behaviour:
SQL Server Resource Adaptor(JDBC Driver) returning XAException with error code XAER_RMERR in case fail-over of SQL Server AG from primary node to standby node while committing an XA Transaction
- Error message/stack trace:
Below is the trace that shows XAException with XAER_RMERR error code returned by SQLServer JDBC driver during fail-over.
[7/30/20 17:20:37:254 CST] 00000369 WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@5e889f7e
WSRdbManagedConnectionImpl@3a76217e
com.ibm.ws.tx.jta.XidImpl@e2696786
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(000001739f05fd25000000017aa729486c90e9918373568c6d645a1d91c7913943fe1a86000001739f05fd25000000017aa729486c90e9918373568c6d645a1d91c7913943fe1a86000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 9f 05 fd 25 00 00 00 01 7a a7 29 48 6c 90 e9 91 83 73 56 8c 6d 64 5a 1d 91 c7 91 39 43 fe 1a 86
Branch Qualifier: 00 00 01 73 9f 05 fd 25 00 00 00 01 7a a7 29 48 6c 90 e9 91 83 73 56 8c 6d 64 5a 1d 91 c7 91 39 43 fe 1a 86 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour E DSRA0302E: XAException occurred. Error code is: XAER_RMERR (-3). Exception is: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour 3 XAException was not a connection error for XAResource com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@5e889f7e
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour < commit Exit
javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:738)
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.commit(SQLServerXAResource.java:807)
at com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit(WSRdbXaResourceImpl.java:361)
at com.ibm.ejs.j2c.XATransactionWrapper.commit(XATransactionWrapper.java:496)
at com.ibm.tx.jta.impl.JTAXAResourceImpl.commit(JTAXAResourceImpl.java:308)
at com.ibm.tx.jta.impl.RegisteredResources.deliverOutcome(RegisteredResources.java:1644)
at com.ibm.tx.jta.impl.RegisteredResources.distributeOutcome(RegisteredResources.java:2003)
at com.ibm.tx.jta.impl.RegisteredResources.distributeCommit(RegisteredResources.java:2315)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1879)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1855)
at com.ibm.tx.jta.impl.TransactionImpl.coreStage2CommitProcessing(TransactionImpl.java:1135)
at com.ibm.tx.jta.impl.TransactionImpl.stage2CommitProcessing(TransactionImpl.java:1173)
at com.ibm.tx.jta.impl.TransactionImpl.processCommit(TransactionImpl.java:1034)
at com.ibm.tx.jta.impl.TransactionImpl.commit(TransactionImpl.java:964)
at com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:439)
at com.ibm.tx.jta.impl.TranManagerSet.commit(TranManagerSet.java:191)
at com.ibm.ws.uow.UOWManagerImpl.uowCommit(UOWManagerImpl.java:807)
.....
.....
.....
Below is the trace where XAER_RMERR error code is converted to XAER_RMFAIL error code, later retried and committed successfully on a different thread.
[8/3/20 13:49:45:363 CST] 0000026e WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@1909f879
WSRdbManagedConnectionImpl@85bb6fef
com.ibm.ws.tx.jta.XidImpl@aad4067c
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a
Branch Qualifier: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[8/3/20 13:49:45:363 CST] 0000026e WSRdbXaResour W Converting XAER_RMERR to XAER_RMFAIL
[8/3/20 13:49:45:379 CST] 0000026e FfdcProvider W com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on C:\IBM\BAW\profiles\Node1Profile\logs\ffdc\AppClusterMember1_ad159ec9_20.08.03_13.49.45.3635376806510343302270.txt com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit 126
[8/3/20 13:49:45:379 CST] 0000026e WSRdbXaResour E DSRA0302E: XAException occurred. Error code is: XAER_RMFAIL (-7). Exception is: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
.....
.....
[8/3/20 13:49:45:520 CST] 0000026e WSRdbXaResour < commit Exit
javax.transaction.xa.XAException
at com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit(WSRdbXaResourceImpl.java:386)
at com.ibm.ejs.j2c.XATransactionWrapper.commit(XATransactionWrapper.java:496)
at com.ibm.tx.jta.impl.JTAXAResourceImpl.commit(JTAXAResourceImpl.java:308)
at com.ibm.tx.jta.impl.RegisteredResources.deliverOutcome(RegisteredResources.java:1644)
at com.ibm.tx.jta.impl.RegisteredResources.distributeOutcome(RegisteredResources.java:2003)
at com.ibm.tx.jta.impl.RegisteredResources.distributeCommit(RegisteredResources.java:2315)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1879)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1855)
at com.ibm.tx.jta.impl.TransactionImpl.coreStage2CommitProcessing(TransactionImpl.java:1135)
at com.ibm.tx.jta.impl.TransactionImpl.stage2CommitProcessing(TransactionImpl.java:1173)
at com.ibm.tx.jta.impl.TransactionImpl.processCommit(TransactionImpl.java:1034)
at com.ibm.tx.jta.impl.TransactionImpl.commit(TransactionImpl.java:964)
at com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:439)
at com.ibm.tx.jta.impl.TranManagerSet.commit(TranManagerSet.java:191)
at com.ibm.ws.uow.UOWManagerImpl.uowCommit(UOWManagerImpl.java:807)
....
....
....
[8/3/20 13:50:55:489 CST] 00000088 WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@e862f1d8
WSRdbManagedConnectionImpl@7ab88f11
com.ibm.ws.tx.jta.XidImpl@aad4067c
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a
Branch Qualifier: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[8/3/20 13:50:55:489 CST] 00000088 WSRdbXaResour 3 XAResource.start was never issued; allowing commit for recovery.
[8/3/20 13:50:55:505 CST] 00000088 WSRdbXaResour < commit Exit
- Any other details that can be helpful:
AG nodes are configured 'sync-commit'
in-doubt xact resolution set to 0
JDBC trace logs
Reproduction code
Driver version
SQL Server JDBC Driver 7.0 & 8.2
SQL Server version
SQL Server AG 2017
Client Operating System
Windows Server 2016, version 10.0
JAVA/JVM version
IBM J9 VM
Table schema
Problem description
During a fail-over test for one of the product when using SQL server AG as back end, we found that there are few XA transactions in SQL Server DTC are in in-doubt state.
After analyzing the trace files, we found that the SQL Server JDBC driver was returning an XAException with an error code of XAER_RMERR on the XAResource.commit due to SQL Server AG fail-over. Websphere application server treats XAER_RMERR as a non-retriable condition as per the XA specification.
We tested with a diagnostic patch on Websphere application server to treat XAER_RMERR as a XAER_RMFAIL(which is retriable) and recreated the scenario.Due to the diagnostic patch Websphere retries the commits which are eventually successful and we no longer finding in-doubt transactions in SQL server DTC.
SQL Server Resource Adaptor(JDBC Driver) should return an XAException with a retriable error code such as XAER_RMFAIL in case fail-over of SQL Server AG from primary node to standby node while committing an XA Transaction.
SQL Server Resource Adaptor(JDBC Driver) returning XAException with error code XAER_RMERR in case fail-over of SQL Server AG from primary node to standby node while committing an XA Transaction
Below is the trace that shows XAException with XAER_RMERR error code returned by SQLServer JDBC driver during fail-over.
[7/30/20 17:20:37:254 CST] 00000369 WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@5e889f7e
WSRdbManagedConnectionImpl@3a76217e
com.ibm.ws.tx.jta.XidImpl@e2696786
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(000001739f05fd25000000017aa729486c90e9918373568c6d645a1d91c7913943fe1a86000001739f05fd25000000017aa729486c90e9918373568c6d645a1d91c7913943fe1a86000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 9f 05 fd 25 00 00 00 01 7a a7 29 48 6c 90 e9 91 83 73 56 8c 6d 64 5a 1d 91 c7 91 39 43 fe 1a 86
Branch Qualifier: 00 00 01 73 9f 05 fd 25 00 00 00 01 7a a7 29 48 6c 90 e9 91 83 73 56 8c 6d 64 5a 1d 91 c7 91 39 43 fe 1a 86 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour E DSRA0302E: XAException occurred. Error code is: XAER_RMERR (-3). Exception is: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour 3 XAException was not a connection error for XAResource com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@5e889f7e
[7/30/20 17:20:37:286 CST] 00000369 WSRdbXaResour < commit Exit
javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:738)
at com.microsoft.sqlserver.jdbc.SQLServerXAResource.commit(SQLServerXAResource.java:807)
at com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit(WSRdbXaResourceImpl.java:361)
at com.ibm.ejs.j2c.XATransactionWrapper.commit(XATransactionWrapper.java:496)
at com.ibm.tx.jta.impl.JTAXAResourceImpl.commit(JTAXAResourceImpl.java:308)
at com.ibm.tx.jta.impl.RegisteredResources.deliverOutcome(RegisteredResources.java:1644)
at com.ibm.tx.jta.impl.RegisteredResources.distributeOutcome(RegisteredResources.java:2003)
at com.ibm.tx.jta.impl.RegisteredResources.distributeCommit(RegisteredResources.java:2315)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1879)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1855)
at com.ibm.tx.jta.impl.TransactionImpl.coreStage2CommitProcessing(TransactionImpl.java:1135)
at com.ibm.tx.jta.impl.TransactionImpl.stage2CommitProcessing(TransactionImpl.java:1173)
at com.ibm.tx.jta.impl.TransactionImpl.processCommit(TransactionImpl.java:1034)
at com.ibm.tx.jta.impl.TransactionImpl.commit(TransactionImpl.java:964)
at com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:439)
at com.ibm.tx.jta.impl.TranManagerSet.commit(TranManagerSet.java:191)
at com.ibm.ws.uow.UOWManagerImpl.uowCommit(UOWManagerImpl.java:807)
.....
.....
.....
Below is the trace where XAER_RMERR error code is converted to XAER_RMFAIL error code, later retried and committed successfully on a different thread.
[8/3/20 13:49:45:363 CST] 0000026e WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@1909f879
WSRdbManagedConnectionImpl@85bb6fef
com.ibm.ws.tx.jta.XidImpl@aad4067c
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a
Branch Qualifier: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[8/3/20 13:49:45:363 CST] 0000026e WSRdbXaResour W Converting XAER_RMERR to XAER_RMFAIL
[8/3/20 13:49:45:379 CST] 0000026e FfdcProvider W com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on C:\IBM\BAW\profiles\Node1Profile\logs\ffdc\AppClusterMember1_ad159ec9_20.08.03_13.49.45.3635376806510343302270.txt com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit 126
[8/3/20 13:49:45:379 CST] 0000026e WSRdbXaResour E DSRA0302E: XAException occurred. Error code is: XAER_RMFAIL (-7). Exception is: com.microsoft.sqlserver.jdbc.SQLServerException: SQL Server did not return a response. The connection has been closed.
.....
.....
[8/3/20 13:49:45:520 CST] 0000026e WSRdbXaResour < commit Exit
javax.transaction.xa.XAException
at com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit(WSRdbXaResourceImpl.java:386)
at com.ibm.ejs.j2c.XATransactionWrapper.commit(XATransactionWrapper.java:496)
at com.ibm.tx.jta.impl.JTAXAResourceImpl.commit(JTAXAResourceImpl.java:308)
at com.ibm.tx.jta.impl.RegisteredResources.deliverOutcome(RegisteredResources.java:1644)
at com.ibm.tx.jta.impl.RegisteredResources.distributeOutcome(RegisteredResources.java:2003)
at com.ibm.tx.jta.impl.RegisteredResources.distributeCommit(RegisteredResources.java:2315)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1879)
at com.ibm.tx.jta.impl.TransactionImpl.internalCommit(TransactionImpl.java:1855)
at com.ibm.tx.jta.impl.TransactionImpl.coreStage2CommitProcessing(TransactionImpl.java:1135)
at com.ibm.tx.jta.impl.TransactionImpl.stage2CommitProcessing(TransactionImpl.java:1173)
at com.ibm.tx.jta.impl.TransactionImpl.processCommit(TransactionImpl.java:1034)
at com.ibm.tx.jta.impl.TransactionImpl.commit(TransactionImpl.java:964)
at com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:439)
at com.ibm.tx.jta.impl.TranManagerSet.commit(TranManagerSet.java:191)
at com.ibm.ws.uow.UOWManagerImpl.uowCommit(UOWManagerImpl.java:807)
....
....
....
[8/3/20 13:50:55:489 CST] 00000088 WSRdbXaResour > commit Entry
com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl@e862f1d8
WSRdbManagedConnectionImpl@7ab88f11
com.ibm.ws.tx.jta.XidImpl@aad4067c
{XidImpl: formatId(57415344), gtrid_length(36), bqual_length(54),
data(00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a00000173b2de55fe000000014b323c4c6b4650ebd3cd42e87a42c9c60b9b3d3d64a9b46a000000010000000000000000000000000001)}
Global Transaction ID: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a
Branch Qualifier: 00 00 01 73 b2 de 55 fe 00 00 00 01 4b 32 3c 4c 6b 46 50 eb d3 cd 42 e8 7a 42 c9 c6 0b 9b 3d 3d 64 a9 b4 6a 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01
Format ID: 1463898948
TWO PHASE
[8/3/20 13:50:55:489 CST] 00000088 WSRdbXaResour 3 XAResource.start was never issued; allowing commit for recovery.
[8/3/20 13:50:55:505 CST] 00000088 WSRdbXaResour < commit Exit
AG nodes are configured 'sync-commit'
in-doubt xact resolution set to 0
JDBC trace logs
Reproduction code