Multiple persistence units not work starting from 3.12.1

sinattieng commented 3 weeks ago

Describe the bug

Starting from quarkus version 3.12.1 my current configuration of multiple datasources not work anymore, indeed on application log I catch this exception :

Caused by: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection [Exception in association of connection to existing transaction] [n/a]
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:63)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:116)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:143)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:54)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:153)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:155)
        at org.hibernate.sql.exec.spi.JdbcSelectExecutor.lambda$list$0(JdbcSelectExecutor.java:85)
        at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:231)
        at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:167)
        at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:265)
        at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:145)
        at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19)
        at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:67)
        at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:204)
        at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:33)
        at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:211)
        at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:83)
        at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:76)
        at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:65)
        at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$2(ConcreteSqmSelectQueryPlan.java:139)
        at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:382)
        at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:302)
        at org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:526)
        at org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:423)
        at org.hibernate.query.spi.AbstractSelectionQuery.getSingleResult(AbstractSelectionQuery.java:555)
        at it.eng.parer.migrate.sacer.os.base.dao.MigrateSacerDao.findDecBakendByName(MigrateSacerDao.java:23)
        at it.eng.parer.migrate.sacer.os.base.dao.MigrateSacerDao_ClientProxy.findDecBakendByName(Unknown Source)
        at it.eng.parer.migrate.sacer.os.base.MigrateOsAbstract.processMigrationRequest(MigrateOsAbstract.java:64)
        at it.eng.parer.migrate.sacer.os.beans.aip.impl.MirateOsAipService.processMigrationAipFromRequest(MirateOsAipService.java:35)
        at it.eng.parer.migrate.sacer.os.beans.aip.impl.MirateOsAipService_Subclass.processMigrationAipFromRequest$$superforward(Unknown Source)
        at it.eng.parer.migrate.sacer.os.beans.aip.impl.MirateOsAipService_Subclass$$function$$9.apply(Unknown Source)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:73)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:62)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:136)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
        at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
        at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
        at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
        at it.eng.parer.migrate.sacer.os.beans.aip.impl.MirateOsAipService_Subclass.processMigrationAipFromRequest(Unknown Source)
        at it.eng.parer.migrate.sacer.os.ip.impl.MirateOsAipService_ClientProxy.processMigrationAipFromRequest(Unknown Source)
        at it.eng.parer.migrate.sacer.os.beans.aip.job.MigrateOsAipJob.processRegisterReq(MigrateOsAipJob.java:54)
        at it.eng.parer.migrate.sacer.os.beans.aip.job.MigrateOsAipJob_ClientProxy.processRegisterReq(Unknown Source)
        at it.eng.parer.migrate.sacer.os.beans.aip.job.MigrateOsAipJob_ScheduledInvoker_processRegisterReq_929c3e5342e271c890dcd0cd9714be91371f85fb.invokeBean(Unknown Source)
        ... 17 more
Caused by: java.sql.SQLException: Exception in association of connection to existing transaction
        at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:130)
        at io.agroal.pool.Poolless.getConnection(Poolless.java:225)
        at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
        at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
        at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:46)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:113)
        ... 63 more
Caused by: java.sql.SQLException: Failed to enlist. Check if a connection from another datasource is already enlisted to the same transaction
        at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:121)
        ... 68 more

My application totally works with the same application.yml until version 3.2.3.Final, below part of my configuration:

quarkus:
  application:
   name: "Migrazione SACER Object Storage"
  devservices:
   enabled: false   
  http:
    body:
      handle-file-uploads: true
      preallocate-body-buffer: true
      uploads-directory: "/tmp"
      delete-uploaded-files-on-end: true
    auth:
     basic: true
     policy:
      role-internal-policy:
         roles-allowed: "admin"       
     permission:
       internal:
          paths: "/admin/*,/api/*"
          policy: "role-internal-policy"
  security:
   users:
     embedded:
       enabled: true        
  transaction-manager:
    default-transaction-timeout: "31536000S"
  datasource:
    db-kind: "oracle" # primary
    sacer: 
      db-kind: "oracle" # secondary
      jdbc:
       driver: "oracle.jdbc.driver.OracleDriver"
       url: ${SACER_JDBC_URL}
      username: ${SACER_USERNAME}
      password: ${SACER_PASSWORD}        
  hibernate-orm:
    packages: "it.eng.parer.migrate.sacer.os.jpa.entity"
    sacer: 
      packages: "it.eng.parer.migrate.sacer.os.jpa.sacer"
      database:
        generation: "none"
      datasource: "sacer"

Note: ${SACER_JDBC_URL}, ${SACER_USERNAME}, ${SACER_PASSWORD} defined as env variables

In addition I have those properties for dev profile

"%dev":
  quarkus:
   http:
     port: 10005
   shutdown:
    timeout: "PT1S"
   datasource: 
     db-kind: "h2"
     username: "sa"
     password: "password"
     jdbc:
       url: "jdbc:h2:file:/tmp/migratedb;DB_CLOSE_DELAY=-1;AUTO_SERVER=TRUE;"
   hibernate-orm:
     validate-in-dev-mode: false
     database:
       generation: "update"
     jdbc:
       statement-fetch-size: 1000
     #fetch:
       #batch-size: 1000 # default 16       
     #validate-in-dev-mode: false
     log:
      sql: false
      format-sql: false
     sacer:
       log:
         sql: true
         format-sql: false

application starts withouth warning or error but when business logic try to execute any query via "sacer" datasource fails, below an example of PersistenceUnit on code:

    @Inject
    @PersistenceUnit(unitName = "sacer")
    EntityManager entityManagerSacer;

Systematically i catch the exeption trying to execute any query (note. in the same transaction i could have multiple JDBC connection with my persistene units). I tried with the latest 3.8.x version and it work BUT if I try to update on 3.12.x doesn't work, same with 3.14.x.

So, in conclusion:

same configuration of multiple datasoruce works with 3.2.x and 3.8.x version NOT starting from 3.12.x
on 3.2.x version via dev mode I could observe only two datasources : default+sacer, starting from 3.8.x in addition a second one default datasouce (quarkus.datasource.*.) and it not also possible to visualize the two persitence unit on dev mode dashboard (loading stucked)

Thank you very much for your support.

Stefano Sinatti

Expected behavior

No response

Actual behavior

No response

How to Reproduce?

No response

Output of `uname -a` or `ver`

No response

Output of `java -version`

No response

Quarkus version or git rev

No response

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

No response

Additional information

No response

nasonawa commented 3 weeks ago

Hey! @sinattieng

You might want to check out this Use multiple datasources in a single transaction which covers the need for XA support when using multiple JDBC data sources. Make sure your JDBC driver supports XA (most should) and that your database server is configured for it.

For Oracle, you can try using the XA driver "oracle.jdbc.xa.client.OracleXADataSource". It could help resolve the issue you're facing.

If anyone else has more insights or experience with this, feel free to chime in! Hope this helps!

quarkus-bot[bot] commented 3 weeks ago

/cc @gsmet (hibernate-orm), @yrodiere (hibernate-orm)

yrodiere commented 3 weeks ago

Hey,

Indeed, if multiple datasources are involved in the same transaction, you must use XA transactions; doing otherwise may result in non-transactional behavior.

Quarkus 3.8 and below was lenient, but 3.9+ fails so that you know something is wrong.

You can find documentation about this here: https://quarkus.io/guides/datasource#datasource-multiple-single-transaction

I thought we had added something to migration guides, but I can't find anything... I will add something.

yrodiere commented 3 weeks ago

I thought we had added something to migration guides, but I can't find anything... I will add something.

I added this: https://github.com/quarkusio/quarkus/wiki/Migration-Guide-3.9#multiple-datasources-single-transaction

Since this error is expected, and documentation includes ways to avoid it, I will close this issue. Feel free to comment if you think there is still something to be done in Quarkus.

sinattieng commented 3 weeks ago

Thank you very much for the support. Enabling XA datasources (both are oracle) I have resolved my issues BUT during boot I have this log:

2024-09-24 12:38:09,983 ; WARN  ; [io.quarkus.agroal.runtime.DataSources] ; (JPA Startup Thread: sacer) ;  ; Datasource sacer enables XA but transaction recovery is not enabled. Please enable transaction recovery by setting quarkus.transaction-manager.enable-recovery=true, otherwise data may be lost if the application is terminated abruptly

so I have to add the enable-recovery (setted true) configuration and everything is ok BUT now I'm facing this warning

2024-09-24 12:41:13,473 ; WARN  ; [com.arjuna.ats.jta] ; (Periodic Recovery) ;  ; XAException:  : javax.transaction.xa.XAException\n    at oracle.jdbc.xa.OracleXAResource.recover(OracleXAResource.java:764)\n    at io.agroal.narayana.RecoveryXAResource.lambda$recover$0(RecoveryXAResource.java:56)\n at io.agroal.narayana.RecoveryXAResource.getConnectedResource(RecoveryXAResource.java:40)\n     at io.agroal.narayana.RecoveryXAResource.recover(RecoveryXAResource.java:56)\n     at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass(XARecoveryModule.java:700)\n    at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:225)\n     at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:167)\n     at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743)\n at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:355)\n

yrodiere commented 3 weeks ago

so I have to add the enable-recovery (setted true) configuration and everything is ok BUT now I'm facing this warning

2024-09-24 12:41:13,473 ; WARN  ; [com.arjuna.ats.jta] ; (Periodic Recovery) ;  ; XAException:  : javax.transaction.xa.XAException\n    at oracle.jdbc.xa.OracleXAResource.recover(OracleXAResource.java:764)\n    at io.agroal.narayana.RecoveryXAResource.lambda$recover$0(RecoveryXAResource.java:56)\n at io.agroal.narayana.RecoveryXAResource.getConnectedResource(RecoveryXAResource.java:40)\n     at io.agroal.narayana.RecoveryXAResource.recover(RecoveryXAResource.java:56)\n     at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass(XARecoveryModule.java:700)\n    at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:225)\n     at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:167)\n     at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743)\n at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:355)\n

This is new to me. Did you sanitize the message, remove any information? There isn't much to work with... As things are, I don't see how you could guess what to do; I think the warning should at least state what failed exactly.

I'd suggest opening a dedicated issue? A reproducer would be nice, but even without that, the stack trace should enable Narayana (transaction layer) maintainers to spot the place where this is logged and to ensure a more meaningful/actionable message is inserted.

quarkusio / quarkus