Since 3.1.2 (#33873) Hibernate schema validation seems flaky and fails due missing tables

[HerrDerb]

With #33873 the moment of execution of Liquibase/Flyway migration has change to a later point of the startup process.

Since this change I experience flaky Hibernate schema validation errors
org.hibernate.tool.schema.spi.SchemaManagementException: Schema-validation: missing table [myTable] on startup

Do we now have a race condition between hibernate schema validation and schema migration?

[quarkus-bot]

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

[yrodiere]

As far as I know we don't experience that in our integration test suite.

Please provide a reproducer, even if it's flaky.

[HerrDerb]

Unfortunately, I was not able to implement a shareable reproducer. I tried one with long running migrations, but this seems not to trigger it. The issue is still present with the newest quarkus version. Maybe the stacktrace does help to see a potential timing issue?

         java.lang.RuntimeException: Failed to start quarkus
            at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
            at io.quarkus.runtime.Application.start(Application.java:101)
            at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
            at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.base/java.lang.reflect.Method.invoke(Method.java:568)
            at io.quarkus.runner.bootstrap.StartupActionImpl.run(StartupActionImpl.java:273)
            at io.quarkus.test.junit.QuarkusTestExtension.doJavaStart(QuarkusTestExtension.java:251)
            at io.quarkus.test.junit.QuarkusTestExtension.ensureStarted(QuarkusTestExtension.java:607)
            at io.quarkus.test.junit.QuarkusTestExtension.beforeAll(QuarkusTestExtension.java:655)
            at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeBeforeAllCallbacks$12(ClassBasedTestDescriptor.java:395)
            at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
            at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.invokeBeforeAllCallbacks(ClassBasedTestDescriptor.java:395)
            at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:211)
            at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:84)
            at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:148)
            ... 51 more

            Caused by:
            jakarta.persistence.PersistenceException: [PersistenceUnit: <default>] Unable to build Hibernate SessionFactory
                at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.persistenceException(FastBootEntityManagerFactoryBuilder.java:126)
                at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:86)
                at io.quarkus.hibernate.orm.runtime.FastBootHibernatePersistenceProvider.createEntityManagerFactory(FastBootHibernatePersistenceProvider.java:74)
                at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:80)
                at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
                at io.quarkus.hibernate.orm.runtime.JPAConfig$LazyPersistenceUnit.get(JPAConfig.java:156)
                at io.quarkus.hibernate.orm.runtime.JPAConfig.getEntityManagerFactory(JPAConfig.java:104)
                at io.quarkus.hibernate.orm.runtime.metrics.HibernateMetricsRecorder$1.accept(HibernateMetricsRecorder.java:31)
                at io.quarkus.hibernate.orm.runtime.metrics.HibernateMetricsRecorder$1.accept(HibernateMetricsRecorder.java:26)
                at io.quarkus.micrometer.runtime.MicrometerRecorder.registerMetrics(MicrometerRecorder.java:175)
                at io.quarkus.deployment.steps.MicrometerProcessor$configureRegistry212[500](https://github.com/QUMEA/care-backend/actions/runs/5315666834/jobs/9624317718#step:6:502)3310.deploy_0(Unknown Source)
                at io.quarkus.deployment.steps.MicrometerProcessor$configureRegistry2125003310.deploy(Unknown Source)
                ... 67 more

                Caused by:
                org.hibernate.tool.schema.spi.SchemaManagementException: Schema-validation: missing table [alert]
                    at org.hibernate.tool.schema.internal.AbstractSchemaValidator.validateTable(AbstractSchemaValidator.java:134)
                    at org.hibernate.tool.schema.internal.GroupedSchemaValidatorImpl.validateTables(GroupedSchemaValidatorImpl.java:46)
                    at org.hibernate.tool.schema.internal.AbstractSchemaValidator.performValidation(AbstractSchemaValidator.java:97)
                    at org.hibernate.tool.schema.internal.AbstractSchemaValidator.doValidation(AbstractSchemaValidator.java:75)
                    at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:293)
                    at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.lambda$process$5(SchemaManagementToolCoordinator.java:143)
                    at [email protected]/java.util.HashMap.forEach(HashMap.java:1421)
                    at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:140)
                    at io.quarkus.hibernate.orm.runtime.observers.SessionFactoryObserverForSchemaExport.sessionFactoryCreated(SessionFactoryObserverForSchemaExport.java:21)
                    at org.hibernate.internal.SessionFactoryObserverChain.sessionFactoryCreated(SessionFactoryObserverChain.java:35)
                    at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:292)
                    at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:84)
                    ... 77 more

[geoand]

I don't think we'll be able to do much without a sample that reproduces the issue (at least some of the time)

[HerrDerb]

Fair enough. As we initialize the datasource during runtime and therefor starting the db migration manually, we kind of workaround this issue.
Feel free to close

[geoand]

Gotcha, thanks for the update.