Hibernate ORM - strange start up failure caused by AnnotationException

[tosuns]

Describe the bug
Currently I'm trying to migrate a JakartaEE with EclipseLink project to quarkus and have another issue with the Hibernate extention.
First of all, my project has no JPA issues within the JakartaEE (EclipseLink) environment. I'm not sure whether I'm using a wrong JPA-annotation and EclipseLink does not complain about it or Hibernate is too strict with it's processing of the JPA-annotation.

First I list all issue related classes

@Entity
@Table(name = "unit",
       schema = "test")
public class Unit
        extends BaseEntity<Unit>
        implements Serializable {

    @Id
    @JoinColumn(name = "name_id",
                columnDefinition = "TEXT",
                nullable = false,
                foreignKey = @ForeignKey(name = "unit_to_text"))
    @ManyToOne
    private Text displayName;

    /* ... getter and setter method and hashcode and equals implementation ... */
}

@Entity
@Table(schema = "test",
       name = "task_measurement_descriptor")
public class MeasurementDescriptor
        extends TaskComponent<MeasurementDescriptor> {

    private static final long serialVersionUID = 6116224369612303819L;

    @MapsId("identifier")
    @ManyToOne
    @JoinColumn(name = "unit_id",
                columnDefinition = "TEXT",
                foreignKey = @ForeignKey(name = "meas_desc_to_unit"))
    private Unit unit;

  /* ... getter & setter method .. */

}

(edit: 2020-09-25)

@Entity
@Table(name = "task_parameter_descriptor",
       schema = "test")
public class ParameterDescriptor
        extends TaskComponent<ParameterDescriptor> {

    private static final long serialVersionUID = -9105640616964717552L;

    @MapsId
    @ManyToOne
    @JoinColumn(name = "unit_id",
                columnDefinition = "TEXT",
                foreignKey = @ForeignKey(name = "para_desc_to_unit"))
    private Unit unit;

    /* ... getter & setter ...*/

}

@Entity
@Table(name = "text",
       schema = "test")
public class Text
        extends BaseEntity<Text> {

    public static final String IDENTIFIER = "identifier";
    private static final long serialVersionUID = -9090566011496432756L;

    @Id
    @Basic
    @Column(name = IDENTIFIER,
            nullable = false)
    private String identifier;

    /* ... getter & setter methods ...*/

}

The issue causing entity is as far as I can tell the Unit entity and it's @Id Annotation, which is declared/assigned to none basic instance variable. The Unit entity is referenced by the MeasurementDescriptor entity as a @ManyToOne relationship.
As I mentioned before I'm not sure whether I'm using the annotation against the JPA specification. But in case of eclipseLink it works and I have no issues.

[edit: 2020-09-25]: Ok I notice something. In my project there is another class ParameterDescriptor
which also has a @ManyToOne relationship to the Unit-Entity just like MeasurementDescriptor. Now if I disable the the @ManyToOne relationship in the ParameterDescriptor class, the mvn clean compile quarkus:dev runs successfully everytime.
I guess Hibernate has some issues with the used declaration, which I would categorize as a bug.

The project in its self compiles via maven without any issues, but if I run mvn clean compile quarkus:dev I get the following exception in the log

[INFO] Scanning for projects...
[INFO]
[INFO] ----------------< quarkus.test:quarkus-hibernate-test >-----------------
[INFO] Building quarkus-hibernate-test 1.0
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ quarkus-hibernate-test ---
[INFO] Deleting C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ quarkus-hibernate-test ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ quarkus-hibernate-test ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 7 source files to C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\target\classes
[WARNING] /C:/Users/<user>/Documents/NetbeansProjects/quarkus/quarkus-hibernate-test/src/main/java/quarkus/hibernate/test/AutoIdEntity.java: C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\src\main\java\quarkus\hibernate\test\AutoIdEntity.java uses unchecked or unsafe operations.
[WARNING] /C:/Users/<user>/Documents/NetbeansProjects/quarkus/quarkus-hibernate-test/src/main/java/quarkus/hibernate/test/AutoIdEntity.java: Recompile with -Xlint:unchecked for details.
[INFO]
[INFO] --- quarkus-maven-plugin:1.7.2.Final:dev (default-cli) @ quarkus-hibernate-test ---
Listening for transport dt_socket at address: 5005
2020-09-21 09:48:36,586 INFO  [org.jbo.threads] (main) JBoss Threads version 3.1.1.Final
2020-09-21 09:48:36,955 INFO  [org.hib.Version] (build-23) HHH000412: Hibernate ORM core version 5.4.21.Final
2020-09-21 09:48:37,293 INFO  [org.hib.Version] (Quarkus Main Thread) HHH000412: Hibernate ORM core version 5.4.21.Final
2020-09-21 09:48:37,309 INFO  [org.hib.ann.com.Version] (Quarkus Main Thread) HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2020-09-21 09:48:37,354 INFO  [org.hib.dia.Dialect] (Quarkus Main Thread) HHH000400: Using dialect: io.quarkus.hibernate.orm.runtime.dialect.QuarkusPostgreSQL10Dialect
2020-09-21 09:48:37,413 INFO  [io.qua.dep.dev.IsolatedDevModeMain] (main) Attempting to start hot replacement endpoint to recover from previous Quarkus startup failure
2020-09-21 09:48:37,414 ERROR [io.qua.run.boo.StartupActionImpl] (Quarkus Main Thread) Error running Quarkus: java.lang.reflect.InvocationTargetException
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$3.run(StartupActionImpl.java:145)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.ExceptionInInitializerError
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at java.base/java.lang.Class.newInstance(Class.java:584)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:60)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:38)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:106)
        at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
        ... 6 more
Caused by: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.<clinit>(ApplicationImpl.zig:195)
        ... 15 more
Caused by: org.hibernate.AnnotationException: A Foreign key refering quarkus.hibernate.test.Unit from quarkus.hibernate.test.MeasurementDescriptor has the wrong number of column. should be 0
        at org.hibernate.cfg.annotations.TableBinder.bindFk(TableBinder.java:646)
        at org.hibernate.cfg.ToOneFkSecondPass.doSecondPass(ToOneFkSecondPass.java:102)
        at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.processEndOfQueue(InFlightMetadataCollectorImpl.java:1823)
        at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.processFkSecondPassesInOrder(InFlightMetadataCollectorImpl.java:1767)
        at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.processSecondPasses(InFlightMetadataCollectorImpl.java:1655)
        at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.complete(MetadataBuildingProcess.java:286)
        at io.quarkus.hibernate.orm.runtime.boot.FastBootMetadataBuilder.build(FastBootMetadataBuilder.java:299)
        at io.quarkus.hibernate.orm.runtime.PersistenceUnitsHolder.createMetadata(PersistenceUnitsHolder.java:101)
        at io.quarkus.hibernate.orm.runtime.PersistenceUnitsHolder.constructMetadataAdvance(PersistenceUnitsHolder.java:73)
        at io.quarkus.hibernate.orm.runtime.PersistenceUnitsHolder.initializeJpa(PersistenceUnitsHolder.java:40)
        at io.quarkus.hibernate.orm.runtime.HibernateOrmRecorder$4.created(HibernateOrmRecorder.java:88)
        at io.quarkus.arc.runtime.ArcRecorder.initBeanContainer(ArcRecorder.java:106)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources1649676420.deploy_0(ArcProcessor$generateResources1649676420.zig:500)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources1649676420.deploy(ArcProcessor$generateResources1649676420.zig:40)
        at io.quarkus.runner.ApplicationImpl.<clinit>(ApplicationImpl.zig:175)
        ... 15 more

But if I repeat mvn clean compile quarkus:dev a couple of times, around 1 of 5 runs quarkus starts without an exception

[INFO] Scanning for projects...
[INFO]
[INFO] ----------------< quarkus.test:quarkus-hibernate-test >-----------------
[INFO] Building quarkus-hibernate-test 1.0
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ quarkus-hibernate-test ---
[INFO] Deleting C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ quarkus-hibernate-test ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ quarkus-hibernate-test ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 7 source files to C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\target\classes
[WARNING] /C:/Users/<user>/Documents/NetbeansProjects/quarkus/quarkus-hibernate-test/src/main/java/quarkus/hibernate/test/AutoIdEntity.java: C:\Users\<user>\Documents\NetbeansProjects\quarkus\quarkus-hibernate-test\src\main\java\quarkus\hibernate\test\AutoIdEntity.java uses unchecked or unsafe operations.
[WARNING] /C:/Users/<user>/Documents/NetbeansProjects/quarkus/quarkus-hibernate-test/src/main/java/quarkus/hibernate/test/AutoIdEntity.java: Recompile with -Xlint:unchecked for details.
[INFO]
[INFO] --- quarkus-maven-plugin:1.7.2.Final:dev (default-cli) @ quarkus-hibernate-test ---
Listening for transport dt_socket at address: 5005
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2020-09-21 09:49:07,166 INFO  [io.quarkus] (Quarkus Main Thread) quarkus-hibernate-test 1.0 on JVM (powered by Quarkus 1.7.2.Final) started in 1.944s.
2020-09-21 09:49:07,168 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2020-09-21 09:49:07,168 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [agroal, cdi, hibernate-orm, jdbc-postgresql, mutiny, narayana-jta, smallrye-context-propagation]

Expected behavior
project compiles and quarkus:dev runs without the above mentioned exception.

Actual behavior
As described above, most of the time quarkus:dev fails with the mentioned exception, but sometimes it runs successfully.

To Reproduce

Link to a small reproducer (preferably a Maven project if the issue is not Gradle-specific).

Or attach an archive containing the reproducer to the issue.

quarkus-hibernate-test.zip

Steps to reproduce the behavior:

1. download the attached project
2. run mvn clean compile quarkus:dev (maybe you have to modify the application.properties file)
3. repeat step (2.) a couple times - at most (10 times) - and see whether the project runs without any exception

Environment (please complete the following information):

• OS: Linux Zakumo 4.4.0-19041-Microsoft #488-Microsoft Mon Sep 01 13:43:00 PST 2020 x86_64 x86_64 x86_64 GNU/Linux

• Output of java -version:

openjdk version "11.0.8" 2020-07-14
OpenJDK Runtime Environment GraalVM CE 20.2.0 (build 11.0.8+10-jvmci-20.2-b03)
OpenJDK 64-Bit Server VM GraalVM CE 20.2.0 (build 11.0.8+10-jvmci-20.2-b03, mixed mode, sharing)

• Quarkus version or git rev: 1.7.2.Final
• Build tool (ie. output of mvnw --version or gradlew --version):

Apache Maven 3.6.3
Maven home: /usr/share/maven
Java version: 11.0.8, vendor: GraalVM Community, runtime: /usr/lib/jvm/graalvm-ce-java11-20.2.0
Default locale: en, platform encoding: UTF-8
OS name: "linux", version: "4.4.0-19041-microsoft", arch: "amd64", family: "unix"

[quarkusbot]

/cc @gsmet, @Sanne

[yrodiere]

I confirm that the error is still present in Quarkus 1.11.3.Final. It does not happen on every boot, but it does happen from time to time. I'll look into this.

[yrodiere]

Turns out it's a bug in Hibernate ORM that can happen with any framework, not just Quarkus.

I opened a ticket (HHH-14467) and will submit a fix. This should resolve itself in Quarkus when we next upgrade the ORM dependency.

[Sanne]

We already included Yoann's fix, but I failed to link the PR to "fixes" this issue.

Doing it now..