Named persistence unit is broken in hibernate-orm-panache-kotlin 2.0.0.Final+

[bboyz269]

Describe the bug

I have 2 persistence units "admin" and "customer" associate with "c.s.c.e.admin" and "c.s.c.e.customer" packages.

Expected behavior

c.s.c.e.admin.Entity should work properly as before (1.13.6.Final).

Actual behavior

c.s.c.e.admin.Entity failed due to not able to resolve the associated persistence unit.

Masked stacktrace

2021-06-30T15:09:15.348+07:00 INFO  [io.quarkus] Profile dev activated. Live Coding activated.
2021-06-30T15:09:15.350+07:00 INFO  [io.quarkus] Installed features: [agroal, cache, cdi, config-yaml, hibernate-orm, hibernate-orm-panache-kotlin, jdbc-mysql, kotlin, narayana-jta, resteasy, resteasy-jackson, security, smallrye-context-propagation, smallrye-health, smallrye-jwt, smallrye-metrics, smallrye-openapi, swagger-ui, vertx, vertx-web]
2021-06-30T15:10:22.623+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012117: TransactionReaper::check processing TX 0:ffffc0a87124:16b3:60dc26ad:0 in state  RUN
2021-06-30T15:10:22.625+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012095: Abort of action id 0:ffffc0a87124:16b3:60dc26ad:0 invoked while multiple threads active within it.
2021-06-30T15:10:22.628+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012381: Action id 0:ffffc0a87124:16b3:60dc26ad:0 completed with multiple threads - thread executor-thread-0 was in progress with com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1636)
/*retracted stack trace*/

2021-06-30T15:10:22.629+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a87124:16b3:60dc26ad:0 aborting with 1 threads active!
2021-06-30T15:10:22.629+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffc0a87124:16b3:60dc26ad:0
2021-06-30T15:10:22.629+07:00 WARN  [com.arj.ats.arjuna] ARJUNA012077: Abort called on already aborted atomic action 0:ffffc0a87124:16b3:60dc26ad:0
2021-06-30T15:10:22.639+07:00 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] HTTP Request to /api/services failed, error id: 62ec378c-2c22-441e-8c2d-8f5d684ade91-1: java.lang.IllegalStateException: The default datasource has not been properly configured. See https://quarkus.io/guides/datasource#jdbc-datasource for information on how to do that.
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.getEntityManager(AbstractJpaOperations.java:62)
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.getEntityManager(AbstractJpaOperations.java:51)
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.findById(AbstractJpaOperations.java:177)
    at c.s.c.e.admin.Entity$Companion.findById(Entity.kt)
/*retracted stack trace*/

2021-06-30T15:10:22.653+07:00 INFO  [access-log] 127.0.0.1 - - "GET /api/services HTTP/1.1" 500 17129 -
2021-06-30T15:10:22.656+07:00 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] HTTP Request to /api/services failed, error id: 62ec378c-2c22-441e-8c2d-8f5d684ade91-2: java.lang.IllegalStateException: The default datasource has not been properly configured. See https://quarkus.io/guides/datasource#jdbc-datasource for information on how to do that.
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.getEntityManager(AbstractJpaOperations.java:62)
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.getEntityManager(AbstractJpaOperations.java:51)
    at io.quarkus.hibernate.orm.panache.common.runtime.AbstractJpaOperations.findById(AbstractJpaOperations.java:177)
    at c.s.c.e.admin.Entity$Companion.findById(Entity.kt)
/*retracted stack trace*/

Configuration

quarkus:
  datasource:
    admin:
    customer:
  hibernate-orm:
    admin:
      packages: c.s.c.e.admin
    customer:
      packages: c.s.c.e.cust

Screenshots

Direct cause would be AbstractJpaOperations.entityToPersistenceUnit lost it value (reverted after being set) to default empty

entityToPersistenceUnit map is being set (12 entries)

entityToPersistenceUnit is empty while being used

Reproduce steps

https://github.com/bboyz269/hibernate-orm-panache-kotlin-multi-persistence-unit

[quarkus-bot[bot]]

/cc @FroMage, @Sanne, @evanchooly, @gsmet, @loicmathieu, @yrodiere

[gsmet]

Thanks for the report. Looks like a very weird issue, any chance you could share a small reproducer?

[bboyz269]

Thanks for the report. Looks like a very weird issue, any chance you could share a small reproducer?

@gsmet Issue is reproducible with bare configuration. Please check this out.
https://github.com/bboyz269/hibernate-orm-panache-kotlin-multi-persistence-unit

[gsmet]

@evanchooly could you have a look to see if it's a Kotlin-specific issue? We have tests for multiple persistence units support for Java I think so maybe it's a corner case but it might as well be Kotlin-related.

Thanks.

[bboyz269]

I think so maybe it's a corner case but it might as well be Kotlin-related.

FYI, switching to io.quarkus:quarkus-hibernate-orm-panache and repository pattern works.
Persistence unit / entity manager could be resolved properly.

@Entity
@Table
class Admin(
    @Id
    @GeneratedValue
    var id: Long = -1,
    var name: String = ""
)
@Singleton
class AdminRepository : PanacheRepository<Admin>

[evanchooly]

after poking around the kotlin bits for a while i converted the project to use java. I get the same error after doing that as I did with kotlin (as shown above). So there's something off here for sure but i'm not 100% it's kotlin related. Perhaps one of the hibernate devs can take a look. @Sanne @FroMage?

[FroMage]

I can look, can you share your Java reproducer please?

[evanchooly]

@FroMage https://github.com/evanchooly/quarkus-java-multi-pu

[FroMage]

Thanks

[evanchooly]

I'm likely missing something obvious to someone more familiar with hibernate's innards but I ran out of places to poke around.

[FroMage]

After quite a lot of hair pulling due to config and trying to follow the multi-tenant docs at https://quarkus.io/guides/hibernate-orm#multitenancy I had to:

• Change the config, to be able to use DEV Services using postgres
• Also to be able to create the DB schema
• Add TenantResolver implementations for each tenant (no idea why one would not be enough)

And then I tried it, and it works. I do get the following exceptions on startup, though, but I think that's another issue:

2021-07-20 16:39:14,548 WARN  [org.hib.eng.jdb.env.int.JdbcEnvironmentInitiator] (JPA Startup Thread: cust) HHH000342: Could not obtain connection to query metadata: javax.enterprise.context.ContextNotActiveException
    at io.quarkus.arc.impl.ClientProxies.getDelegate(ClientProxies.java:40)
    at ac.me.entity.CustTenantResolver_ClientProxy.arc$delegate(CustTenantResolver_ClientProxy.zig:42)
    at ac.me.entity.CustTenantResolver_ClientProxy.getDefaultTenantId(CustTenantResolver_ClientProxy.zig:128)
    at io.quarkus.hibernate.orm.runtime.tenant.HibernateMultiTenantConnectionProvider.getAnyConnectionProvider(HibernateMultiTenantConnectionProvider.java:37)
    at org.hibernate.engine.jdbc.connections.spi.AbstractMultiTenantConnectionProvider.getAnyConnection(AbstractMultiTenantConnectionProvider.java:26)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$MultiTenantConnectionProviderJdbcConnectionAccess.obtainConnection(JdbcEnvironmentInitiator.java:208)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:68)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:35)
    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:101)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:263)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:237)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:214)
    at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:51)
    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.configureService(StandardServiceRegistryImpl.java:107)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:246)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:214)
    at org.hibernate.boot.internal.SessionFactoryOptionsBuilder.<init>(SessionFactoryOptionsBuilder.java:263)
    at io.quarkus.hibernate.orm.runtime.recording.PrevalidatedQuarkusMetadata.buildSessionFactoryOptionsBuilder(PrevalidatedQuarkusMetadata.java:69)
    at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:69)
    at io.quarkus.hibernate.orm.runtime.FastBootHibernatePersistenceProvider.createEntityManagerFactory(FastBootHibernatePersistenceProvider.java:67)
    at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:80)
    at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
    at io.quarkus.hibernate.orm.runtime.JPAConfig$LazyPersistenceUnit.get(JPAConfig.java:149)
    at io.quarkus.hibernate.orm.runtime.JPAConfig$1.run(JPAConfig.java:58)
    at java.base/java.lang.Thread.run(Thread.java:829)

2021-07-20 16:39:14,548 WARN  [org.hib.eng.jdb.env.int.JdbcEnvironmentInitiator] (JPA Startup Thread: admin) HHH000342: Could not obtain connection to query metadata: javax.enterprise.context.ContextNotActiveException
    at io.quarkus.arc.impl.ClientProxies.getDelegate(ClientProxies.java:40)
    at ac.me.entity.AdminTenantResolver_ClientProxy.arc$delegate(AdminTenantResolver_ClientProxy.zig:42)
    at ac.me.entity.AdminTenantResolver_ClientProxy.getDefaultTenantId(AdminTenantResolver_ClientProxy.zig:128)
    at io.quarkus.hibernate.orm.runtime.tenant.HibernateMultiTenantConnectionProvider.getAnyConnectionProvider(HibernateMultiTenantConnectionProvider.java:37)
    at org.hibernate.engine.jdbc.connections.spi.AbstractMultiTenantConnectionProvider.getAnyConnection(AbstractMultiTenantConnectionProvider.java:26)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$MultiTenantConnectionProviderJdbcConnectionAccess.obtainConnection(JdbcEnvironmentInitiator.java:208)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:68)
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:35)
    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:101)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:263)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:237)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:214)
    at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:51)
    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.configureService(StandardServiceRegistryImpl.java:107)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:246)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:214)
    at org.hibernate.boot.internal.SessionFactoryOptionsBuilder.<init>(SessionFactoryOptionsBuilder.java:263)
    at io.quarkus.hibernate.orm.runtime.recording.PrevalidatedQuarkusMetadata.buildSessionFactoryOptionsBuilder(PrevalidatedQuarkusMetadata.java:69)
    at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:69)
    at io.quarkus.hibernate.orm.runtime.FastBootHibernatePersistenceProvider.createEntityManagerFactory(FastBootHibernatePersistenceProvider.java:67)
    at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:80)
    at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
    at io.quarkus.hibernate.orm.runtime.JPAConfig$LazyPersistenceUnit.get(JPAConfig.java:149)
    at io.quarkus.hibernate.orm.runtime.JPAConfig$1.run(JPAConfig.java:58)
    at java.base/java.lang.Thread.run(Thread.java:829)

I can't quite understand why you had one data source as multitenant: https://github.com/bboyz269/hibernate-orm-panache-kotlin-multi-persistence-unit/blob/main/src/main/resources/application.yml#L21 Is it by mistake or on purpose?

[FroMage]

My working project is at https://github.com/FroMage/quarkus-java-multi-pu

[bboyz269]

@FroMage

I can't quite understand why you had one data source as multitenant

It's intended. To say briefly, in order to resolve the tenant (which db schema to use for which tenant), my app needs to access another "admin" database, which manage all the tenant information.

Are you suggesting that adding "TenantResolver" for each persistence unit would solve the problem?

[FroMage]

I suppose so, at least I had an error when I tried your config.

[bboyz269]

I suppose so, at least I had an error when I tried your config.

@FroMage I tried and got the same result (error due to AbstractJpaOperations#entityToPersistenceUnit being empty). I seems that private static volatile Map<String, String> entityToPersistenceUnit is somehow messed up in kotlin.

[bboyz269]

I did some more digging on AbstractJpaOperations#entityToPersistenceUnit and find the difference between "hibernate-orm-kotlin" and "hibernate-orm" is that:

One is build time work (entityToPersistenceUnit is updated in build thread)

The other is runtime work (entityToPersistenceUnit is updated in quarkus main thread)

I don't have any knowledge of Quarkus's extension framework ("Favor build time work over runtime work") but it seems that the former does not register entityToPersistenceUnit mapping properly at runetime, causing problems with named persistence unit setup.

Do you think this worth investigating @evanchooly @FroMage ? I updated my repo with as reproducible (1 default datasource, 1 named persistence unit, fixed devservices)

[FroMage]

@evanchooly could you look at this please?

[evanchooly]

Definitely.

[loicmathieu]

There is a report of the same issue here: #20882 and I chased it down to the same causes, the entity to PU map is empty inside the Kotlin extension. @evanchooly @FroMage did you make any progress on it ?

Both Hibernate and Kotlin does it inside a STATIC_INIT build step so I don't understand why it works in one but not in the other.

[evanchooly]

Pretty sure this was fixed in a later release

[bboyz269]

I just tested that this issue still exists in .2.4.0.Final".
There seems to be open PR that address this. Hope it get merged and released soon.

[loicmathieu]

Fixed by https://github.com/quarkusio/quarkus/pull/21079