Spring Boot 3 compiled to native getting Postgresql JDBC errors

[edeandrea]

I have a simple Spring Boot 3 application that uses Spring Data JPA (https://github.com/edeandrea/quarkus-for-spring-devs-examples/tree/quarkus-for-spring-devs-talk-sb3/chapter-4/chapter-4-spring-data-jpa).

The application's configuration (https://github.com/edeandrea/quarkus-for-spring-devs-examples/blob/quarkus-for-spring-devs-talk-sb3/chapter-4/chapter-4-spring-data-jpa/src/main/resources/application.yml) has spring.jpa.hibernate.ddl-auto=create-drop and there is an import.sql file in src/main/resources.

After compiling to native (GraalVM CE 22.3.0 (build 17.0.5+8-jvmci-22.3-b08)) using the command ./mvnw -Pnative native:compile and running the application, it starts up but the data in import.sql does not get loaded. Instead I see the following error.

NOTE: This was working fine in 3.0.0-RC1, but then broke with the same error in 3.0.0-RC2.

2022-11-28T10:14:33.953-05:00  WARN 62921 --- [           main] o.h.dialect.PostgreSQLPGObjectJdbcType   : PostgreSQL JDBC driver classes are inaccessible and thus, certain DDL types like JSONB, JSON, GEOMETRY can not be used!

java.lang.NoSuchMethodException: org.postgresql.util.PGobject.<init>()
        at java.base@17.0.5/java.lang.Class.getConstructor0(DynamicHub.java:3585) ~[chapter-4-spring-data-jpa:na]
        at java.base@17.0.5/java.lang.Class.getConstructor(DynamicHub.java:2271) ~[chapter-4-spring-data-jpa:na]
        at org.hibernate.dialect.PostgreSQLPGObjectJdbcType.<clinit>(PostgreSQLPGObjectJdbcType.java:50) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.PostgreSQLDialect.registerColumnTypes(PostgreSQLDialect.java:231) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.Dialect.contributeTypes(Dialect.java:1341) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.PostgreSQLDialect.contributeTypes(PostgreSQLDialect.java:1229) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.handleTypes(MetadataBuildingProcess.java:386) ~[na:na]
        at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.complete(MetadataBuildingProcess.java:143) ~[na:na]
        at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.metadata(EntityManagerFactoryBuilderImpl.java:1350) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1421) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:66) ~[na:na]
        at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:376) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:409) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:396) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:352) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1797) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1747) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:599) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1130) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:905) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:432) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:308) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.acme.Chapter4SpringDataJpaApplication.main(Chapter4SpringDataJpaApplication.java:10) ~[chapter-4-spring-data-jpa:na]

Here is the full log:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.0.0)

2022-11-28T10:14:33.852-05:00  INFO 62921 --- [           main] o.acme.Chapter4SpringDataJpaApplication  : Starting AOT-processed Chapter4SpringDataJpaApplication using Java 17.0.5 with PID 62921 (/Users/edeandre/workspaces/quarkus-ebook/quarkus-for-spring-devs-examples/chapter-4/chapter-4-spring-data-jpa/target/chapter-4-spring-data-jpa started by edeandre in /Users/edeandre/workspaces/quarkus-ebook/quarkus-for-spring-devs-examples/chapter-4/chapter-4-spring-data-jpa)
2022-11-28T10:14:33.853-05:00  INFO 62921 --- [           main] o.acme.Chapter4SpringDataJpaApplication  : No active profile set, falling back to 1 default profile: "default"
2022-11-28T10:14:33.877-05:00  INFO 62921 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-11-28T10:14:33.878-05:00  INFO 62921 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-11-28T10:14:33.878-05:00  INFO 62921 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/10.1.1]
2022-11-28T10:14:33.882-05:00  INFO 62921 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-11-28T10:14:33.882-05:00  INFO 62921 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 29 ms
2022-11-28T10:14:33.900-05:00  INFO 62921 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-11-28T10:14:33.901-05:00  INFO 62921 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 6.1.5.Final
2022-11-28T10:14:33.903-05:00  WARN 62921 --- [           main] org.hibernate.orm.deprecation            : HHH90000021: Encountered deprecated setting [javax.persistence.sharedCache.mode], use [jakarta.persistence.sharedCache.mode] instead
2022-11-28T10:14:33.905-05:00  INFO 62921 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-11-28T10:14:33.948-05:00  INFO 62921 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@726fe6b2
2022-11-28T10:14:33.948-05:00  INFO 62921 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-11-28T10:14:33.952-05:00  INFO 62921 --- [           main] SQL dialect                              : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect
2022-11-28T10:14:33.953-05:00  WARN 62921 --- [           main] o.h.dialect.PostgreSQLPGObjectJdbcType   : PostgreSQL JDBC driver classes are inaccessible and thus, certain DDL types like JSONB, JSON, GEOMETRY can not be used!

java.lang.NoSuchMethodException: org.postgresql.util.PGobject.<init>()
        at java.base@17.0.5/java.lang.Class.getConstructor0(DynamicHub.java:3585) ~[chapter-4-spring-data-jpa:na]
        at java.base@17.0.5/java.lang.Class.getConstructor(DynamicHub.java:2271) ~[chapter-4-spring-data-jpa:na]
        at org.hibernate.dialect.PostgreSQLPGObjectJdbcType.<clinit>(PostgreSQLPGObjectJdbcType.java:50) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.PostgreSQLDialect.registerColumnTypes(PostgreSQLDialect.java:231) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.Dialect.contributeTypes(Dialect.java:1341) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.dialect.PostgreSQLDialect.contributeTypes(PostgreSQLDialect.java:1229) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.handleTypes(MetadataBuildingProcess.java:386) ~[na:na]
        at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.complete(MetadataBuildingProcess.java:143) ~[na:na]
        at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.metadata(EntityManagerFactoryBuilderImpl.java:1350) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1421) ~[chapter-4-spring-data-jpa:6.1.5.Final]
        at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:66) ~[na:na]
        at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:376) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:409) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:396) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:352) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1797) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1747) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:599) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1130) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:905) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584) ~[chapter-4-spring-data-jpa:6.0.2]
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:432) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:308) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291) ~[chapter-4-spring-data-jpa:3.0.0]
        at org.acme.Chapter4SpringDataJpaApplication.main(Chapter4SpringDataJpaApplication.java:10) ~[chapter-4-spring-data-jpa:na]

2022-11-28T10:14:34.045-05:00  WARN 62921 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Warning Code: 0, SQLState: 00000
2022-11-28T10:14:34.045-05:00  WARN 62921 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : table "fruits" does not exist, skipping
2022-11-28T10:14:34.072-05:00  INFO 62921 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-11-28T10:14:34.073-05:00  INFO 62921 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-11-28T10:14:34.101-05:00  WARN 62921 --- [           main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
2022-11-28T10:14:34.117-05:00  WARN 62921 --- [           main] i.m.c.i.binder.jvm.JvmGcMetrics          : GC notifications will not be available because MemoryPoolMXBeans are not provided by the JVM
2022-11-28T10:14:34.120-05:00  INFO 62921 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-11-28T10:14:34.122-05:00  INFO 62921 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-11-28T10:14:34.123-05:00  INFO 62921 --- [           main] o.acme.Chapter4SpringDataJpaApplication  : Started Chapter4SpringDataJpaApplication in 0.288 seconds (process running for 0.304)

[wilkinsona]

That looks like a warning rather than an error to me and it's due to some reflection in Hibernate's Postgres support that isn't covered by its reachability metadata. I've opened oracle/graalvm-reachability-metadata#131.

Using import.sql is atypical for a Spring Boot app. We generally recommend using schema.sql and data.sql files that will be included automatically in the native image and processed by Spring Boot. For the import.sql to be found and processed by Hibernate, I think you'll have to manually configure Graal to include it at the moment. Have you done that?

[edeandrea]

I haven't done that, but will try renaming it to data.sql and see what happens. I've been using import.sql in this app for a year through Spring Boot 2.6.x & 2.7.x upgrades, as well as with 3.0.0-RC1. It didn't break until 3.0.0-RC2.

I'll report back what I find. Thanks for looking into this so quick!

[edeandrea]

So changing import.sql to data.sql as well as adding

spring.jpa.defer-datasource-initialization=true
spring.sql.init.mode=always

fixes the runtime issue, but it breaks my unit tests (https://github.com/edeandrea/quarkus-for-spring-devs-examples/blob/quarkus-for-spring-devs-talk-sb3/chapter-4/chapter-4-spring-data-jpa/src/test/java/org/acme/repository/FruitRepositoryTests.java).

Seems the data.sql does not get run when the tests run. The test expects to find data already in the database, which after making this change, is not there.

Having import.sql and everything works fine in the test, but then things are broken at runtime.

[wilkinsona]

There are several reasons why that could be the case and you haven't provided enough information for us to be able to say which one it may be. I suspect the duplicate application.yml files that you have on the classpath may be part of the problem but that's only a guess as you haven't described the changes that you made in sufficient detail for us to know for sure.

If you have any further questions, please follow up on Stack Overflow or Gitter. As mentioned in the guidelines for contributing, we prefer to use GitHub issues only for bugs and enhancements.