0

I have a spring boot project and use spring data jpa / hibernate to manage my data layer. The database is created by hibernate based on my entities. Here below my setting:

spring.jpa.hibernate.ddl-auto = create-drop
spring.jpa.properties.hibernate.dialect = org.hibernate.dialect.PostgreSQL82Dialect
spring.jpa.properties.hibernate.jdbc.lob.non_contextual_creation=true
spring.datasource.initialization-mode=always

Everything works fine but after Spring starts i get a lot of errors in the logs. Here below an an example of what I get when i run some integration tests:

 .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.1.RELEASE)

2020-02-28 11:00:41.965  INFO 7325 --- [           main] c.b.p12.api.business.MemberManagerIT     : Starting MemberManagerIT on Admins-MBP with PID 7325 (started by admin in /Users/admin/Documents/PROGRAMMING/OPENCLASSROOMS/P12/ZebraInLove/P12-REPO/p12-api/p12-api-business)
2020-02-28 11:00:41.967  INFO 7325 --- [           main] c.b.p12.api.business.MemberManagerIT     : No active profile set, falling back to default profiles: default
2020-02-28 11:00:42.656  INFO 7325 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data repositories in DEFAULT mode.
2020-02-28 11:00:42.747  INFO 7325 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 82ms. Found 7 repository interfaces.
2020-02-28 11:00:43.234  INFO 7325 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-28 11:00:43.509  INFO 7325 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2020-02-28 11:00:43.591  INFO 7325 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate Core {5.4.8.Final}
2020-02-28 11:00:43.840  INFO 7325 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2020-02-28 11:00:43.997  INFO 7325 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2020-02-28 11:00:44.129  INFO 7325 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2020-02-28 11:00:44.155  INFO 7325 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL82Dialect
Hibernate: alter table declared_location drop constraint FKdwbc02mn6m4s7bp0tdcc4i29n
2020-02-28 11:00:45.118  WARN 7325 --- [           main] o.h.t.s.i.ExceptionHandlerLoggedImpl     : GenerationTarget encountered exception accepting command : Error executing DDL "alter table declared_location drop constraint FKdwbc02mn6m4s7bp0tdcc4i29n" via JDBC Statement

org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "alter table declared_location drop constraint FKdwbc02mn6m4s7bp0tdcc4i29n" via JDBC Statement
    at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) ~[hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.applySqlString(SchemaDropperImpl.java:375) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.applySqlStrings(SchemaDropperImpl.java:359) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.applyConstraintDropping(SchemaDropperImpl.java:331) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.dropFromMetadata(SchemaDropperImpl.java:230) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.performDrop(SchemaDropperImpl.java:154) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.doDrop(SchemaDropperImpl.java:126) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.internal.SchemaDropperImpl.doDrop(SchemaDropperImpl.java:112) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:145) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:73) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:320) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:462) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
    at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1249) [hibernate-core-5.4.8.Final.jar:5.4.8.Final]
(...)

Caused by: org.postgresql.util.PSQLException: ERROR: relation "declared_location" does not exist


As it looks, the problem is that already at start Hibernate tries to drop constraint on a table that has not been created yet. Which of course produces an error.

Further in the logs, it shows that :

  • Hibernate will try to drop that table
Hibernate: drop table if exists declared_location cascade
2020-02-28 11:00:45.141  WARN 7325 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Warning Code: 0, SQLState: 00000
2020-02-28 11:00:45.141  WARN 7325 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : table "declared_location" does not exist, skipping

then create it:

Hibernate: create table declared_location (id varchar(255) not null, address varchar(255), latitude float8 not null, longitude float8 not null, member_id varchar(255), primary key (id))

then alter it

Hibernate: alter table declared_location add constraint FKdwbc02mn6m4s7bp0tdcc4i29n foreign key (member_id) references member

So at the end, my tests pass but I'm just annoyed with these very long logs full of pseudo errors. What can I do to avoid this?

Julien Berthoud
  • 721
  • 8
  • 24
  • You are using old Hibernate 5.1 and old `PostgreSQL82Dialect` dialect for PostgreSQL 8.2. Why not to update and see if the problem is still there? – Karol Dowbecki Feb 28 '20 at 10:51
  • I've switched to PostgreSQL9Dialect and now use the latest version of spring-boot-starter-data-jpa but it didn't change anything. – Julien Berthoud Feb 28 '20 at 13:41

1 Answers1

0

I think spring.jpa.hibernate.ddl-auto = create-drop is doing drop-create-drop. If you use mock data you are ensured a clean database at the cost of a attempted drop prior to creation.

How does spring.jpa.hibernate.ddl-auto property exactly work in Spring?