search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.53k stars 2.61k forks source link

Narayana throws an exception when working with the latest MSSQL server #42135

Closed fedinskiy closed 1 week ago

fedinskiy commented 1 month ago

Describe the bug

I have an application, which uses Quarkus transaction programmatic API. When I run the application with the latest MS SQL server (mcr.microsoft.com/mssql/rhel/server:2022-CU14-rhel-9.1) it fails when making a transaction in XA mode. At the same time, it works fine with 2022-CU13-rhel-9.1. Since the version 2022-CU14-rhel-9.1 is where 2022-latest tag points to (and therefore, the one used by Quarkus DevMode), this is going to affect a lot of users.

Expected behavior

Transaction passes

Actual behavior

13:54:47,462 INFO  [app] 13:54:46,437 ARJUNA016061: TransactionImple.enlistResource - XAResource.start returned: XAException.XAER_RMERR for < formatId=131077, gtrid_length=38, bqual_length=36, tx_uid=0:ffff0a057e34:b1f7:66a23cfb:2b, node_name=quarkus-qe, branch_uid=0:ffff0a057e34:b1f7:66a23cfb:69, subordinatenodename=null, eis_name=0 >: javax.transaction.xa.XAException: com.microsoft.sqlserver.jdbc.SQLServerException: Failed to create the XA control connection. Error: "The connection is closed."
13:54:47,462 INFO  [app]    at com.microsoft.sqlserver.jdbc.SQLServerXAResource.dtc_XA_interface(SQLServerXAResource.java:775)
13:54:47,462 INFO  [app]    at com.microsoft.sqlserver.jdbc.SQLServerXAResource.start(SQLServerXAResource.java:809)
13:54:47,462 INFO  [app]    at io.quarkus.ts.transactions.recovery.driver.CrashingXAResource.start(CrashingXAResource.java:97)
13:54:47,462 INFO  [app]    at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:153)
13:54:47,462 INFO  [app]    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:648)
13:54:47,462 INFO  [app]    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:408)
13:54:47,462 INFO  [app]    at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:120)
13:54:47,462 INFO  [app]    at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:292)
13:54:47,462 INFO  [app]    at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
13:54:47,462 INFO  [app]    at io.agroal.api.AgroalDataSource_EkaD-FEfbv_myExtdBtVX28RsOE_Synthetic_ClientProxy.getConnection(Unknown Source)
13:54:47,462 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:43)
13:54:47,462 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:39)
13:54:47,462 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService.withTransaction(InjectedUserTransactionRecoveryService.java:27)
13:54:47,463 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransaction(TransactionRecoveryService.java:25)
13:54:47,463 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService_ClientProxy.makeTransaction(Unknown Source)
13:54:47,463 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource.makeTransaction(TransactionLogsResource.java:53)
13:54:47,463 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource$quarkusrestinvoker$makeTransaction_40fe194699cb8d60fafa6ea499679657f4250adb.invoke(Unknown Source)
13:54:47,463 INFO  [app]    at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
13:54:47,463 INFO  [app]    at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
13:54:47,463 INFO  [app]    at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
13:54:47,463 INFO  [app]    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:599)
13:54:47,463 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
13:54:47,463 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
13:54:47,463 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1521)
13:54:47,463 INFO  [app]    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
13:54:47,463 INFO  [app]    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
13:54:47,463 INFO  [app]    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
13:54:47,463 INFO  [app]    at java.base/java.lang.Thread.run(Thread.java:1583)
13:54:47,463 INFO  [app] 13:54:46,437 ARJUNA016138: Failed to enlist XA resource io.agroal.narayana.BaseXAResource@1fd8ede7: jakarta.transaction.SystemException: TransactionImple.enlistResource - XAResource.start ARJUNA016054: could not register transaction: < formatId=131077, gtrid_length=38, bqual_length=36, tx_uid=0:ffff0a057e34:b1f7:66a23cfb:2b, node_name=quarkus-qe, branch_uid=0:ffff0a057e34:b1f7:66a23cfb:69, subordinatenodename=null, eis_name=0 >
13:54:47,463 INFO  [app]    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:709)
13:54:47,463 INFO  [app]    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:408)
13:54:47,463 INFO  [app]    at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:120)
13:54:47,464 INFO  [app]    at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:292)
13:54:47,464 INFO  [app]    at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
13:54:47,464 INFO  [app]    at io.agroal.api.AgroalDataSource_EkaD-FEfbv_myExtdBtVX28RsOE_Synthetic_ClientProxy.getConnection(Unknown Source)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:43)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:39)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService.withTransaction(InjectedUserTransactionRecoveryService.java:27)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransaction(TransactionRecoveryService.java:25)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService_ClientProxy.makeTransaction(Unknown Source)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource.makeTransaction(TransactionLogsResource.java:53)
13:54:47,464 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource$quarkusrestinvoker$makeTransaction_40fe194699cb8d60fafa6ea499679657f4250adb.invoke(Unknown Source)
13:54:47,464 INFO  [app]    at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
13:54:47,464 INFO  [app]    at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
13:54:47,464 INFO  [app]    at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
13:54:47,464 INFO  [app]    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:599)
13:54:47,464 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
13:54:47,464 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
13:54:47,464 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1521)
13:54:47,464 INFO  [app]    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
13:54:47,464 INFO  [app]    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
13:54:47,465 INFO  [app]    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
13:54:47,465 INFO  [app]    at java.base/java.lang.Thread.run(Thread.java:1583)
13:54:47,465 INFO  [app] 13:54:46,439 HTTP Request to /transaction-logs?rollback=false&executor=INJECTED_USER_TRANSACTION failed, error id: a280e634-dc76-41b7-8d3e-096fc3992ef8-1: java.lang.RuntimeException: java.lang.RuntimeException: java.sql.SQLException: Exception in association of connection to existing transaction
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService.withTransaction(InjectedUserTransactionRecoveryService.java:31)
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransaction(TransactionRecoveryService.java:25)
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService_ClientProxy.makeTransaction(Unknown Source)
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource.makeTransaction(TransactionLogsResource.java:53)
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionLogsResource$quarkusrestinvoker$makeTransaction_40fe194699cb8d60fafa6ea499679657f4250adb.invoke(Unknown Source)
13:54:47,465 INFO  [app]    at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
13:54:47,465 INFO  [app]    at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
13:54:47,465 INFO  [app]    at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
13:54:47,465 INFO  [app]    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:599)
13:54:47,465 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
13:54:47,465 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
13:54:47,465 INFO  [app]    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1521)
13:54:47,465 INFO  [app]    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
13:54:47,465 INFO  [app]    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
13:54:47,465 INFO  [app]    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
13:54:47,465 INFO  [app]    at java.base/java.lang.Thread.run(Thread.java:1583)
13:54:47,465 INFO  [app] Caused by: java.lang.RuntimeException: java.sql.SQLException: Exception in association of connection to existing transaction
13:54:47,465 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:54)
13:54:47,466 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:39)
13:54:47,466 INFO  [app]    at io.quarkus.ts.transactions.recovery.service.InjectedUserTransactionRecoveryService.withTransaction(InjectedUserTransactionRecoveryService.java:27)
13:54:47,466 INFO  [app]    ... 15 more
13:54:47,466 INFO  [app] Caused by: java.sql.SQLException: Exception in association of connection to existing transaction
13:54:47,466 INFO  [app]    at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:130)
13:54:47,466 INFO  [app]    at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:292)
13:54:47,466 INFO  [app]    at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
13:54:47,466 INFO  [app]    at io.agroal.api.AgroalDataSource_EkaD-FEfbv_myExtdBtVX28RsOE_Synthetic_ClientProxy.getConnection(Unknown Source)
13:54:47,466 INFO  [app]    at io.quarkus.ts.transactions.recovery.TransactionRecoveryService.makeTransactionInternal(TransactionRecoveryService.java:43)
13:54:47,466 INFO  [app]    ... 17 more
13:54:47,466 INFO  [app] Caused by: java.sql.SQLException: Unable to enlist connection to existing transaction
13:54:47,466 INFO  [app]    at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:121)
13:54:47,466 INFO  [app]    ... 21 more
13:54:48,634 INFO  [app] Service stopped (Quarkus JVM mode)

How to Reproduce?

  1. git clone git@github.com:quarkus-qe/quarkus-test-suite.git && cd quarkus-test-suite
  2. This fails: mvn clean verify -pl sql-db/narayana-transactions/ -Dit.test=MssqlTransactionGeneralUsageIT -Dquarkus.platform.version=3.12.3 -Dmssql.image=mcr.microsoft.com/mssql/rhel/server:2022-CU14-rhel-9.1 -Dreruns=0
  3. This also fails: mvn clean verify -pl sql-db/narayana-transactions/ -Dit.test=MssqlTransactionGeneralUsageIT -Dquarkus.platform.version=3.12.3 -Dmssql.image=mcr.microsoft.com/mssql/rhel/server:2022-latest -Dreruns=0
  4. this succeeds mvn clean verify -pl sql-db/narayana-transactions/ -Dit.test=MssqlTransactionGeneralUsageIT -Dquarkus.platform.version=3.12.3 -Dmssql.image=mcr.microsoft.com/mssql/rhel/server:2022-CU13-rhel-9.1 -Dreruns=0

Output of uname -a or ver

4.18.0-553.5.1.el8_10.x86_64

Output of java -version

17.0.7, vendor: Red Hat, Inc.

Quarkus version or git rev

3.12.3

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.9.6 (bc0240f3c744dd6b6ec2920b3cd08dcc295161ae)

Additional information

No response

quarkus-bot[bot] commented 1 month ago

/cc @mmusgrov (narayana)

jedla97 commented 1 week ago

This was problem on TS side as they changes trusting certificate on mysql side. Maybe some Quarkus user but it's not a bug on Quarkus side. I belive we can close this issue

gsmet commented 1 week ago

Thanks for the feedback.