Very slow Spring Boot application startup

Question

I have a simple Spring Boot application that connects to a PostgreSQL database and serves as a JSON service. Somehow the startup has become very slow, see timings 10:37:10 and 10:38:00:

2015-05-09 10:37:09.649  INFO 20880 --- [lication.main()] o.apache.catalina.core.StandardService   : Starting service Tomcat
2015-05-09 10:37:09.651  INFO 20880 --- [lication.main()] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.0.20
2015-05-09 10:37:09.767  INFO 20880 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2015-05-09 10:37:09.767  INFO 20880 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 2970 ms
2015-05-09 10:37:09.979  INFO 20880 --- [ost-startStop-1] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'dispatcherServlet' to [/]
2015-05-09 10:37:09.985  INFO 20880 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'characterEncodingFilter' to: [/*]
2015-05-09 10:37:10.105  INFO 20880 --- [lication.main()] o.s.j.d.DriverManagerDataSource          : Loaded JDBC driver: org.postgresql.Driver
2015-05-09 10:37:10.214  INFO 20880 --- [lication.main()] j.LocalContainerEntityManagerFactoryBean : Building JPA container EntityManagerFactory for persistence unit 'default'
2015-05-09 10:37:10.233  INFO 20880 --- [lication.main()] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [
    name: default
    ...]
2015-05-09 10:37:10.585  INFO 20880 --- [lication.main()] org.hibernate.Version                    : HHH000412: Hibernate Core {4.3.8.Final}
2015-05-09 10:37:10.587  INFO 20880 --- [lication.main()] org.hibernate.cfg.Environment            : HHH000206: hibernate.properties not found
2015-05-09 10:37:10.589  INFO 20880 --- [lication.main()] org.hibernate.cfg.Environment            : HHH000021: Bytecode provider name : javassist
2015-05-09 10:37:10.968  INFO 20880 --- [lication.main()] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {4.0.5.Final}
2015-05-09 10:38:00.023  INFO 20880 --- [lication.main()] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect
2015-05-09 10:38:00.041  INFO 20880 --- [lication.main()] o.h.e.jdbc.internal.LobCreatorBuilder    : HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
2015-05-09 10:38:00.274  INFO 20880 --- [lication.main()] o.h.h.i.ast.ASTQueryTranslatorFactory    : HHH000397: Using ASTQueryTranslatorFactory

Any thoughts? Is there anything I can do to diagnose the problem?

Solution 1

For Spring Boot you can set this in your application.properties file:

spring.jpa.properties.hibernate.temp.use_jdbc_metadata_defaults=false

I also found that I needed to set another property or I would get the error "org.hibernate.HibernateException: Access to DialectResolutionInfo cannot be null when 'hibernate.dialect' not set". To rectify that I set this property:

spring.jpa.database-platform=org.hibernate.dialect.PostgreSQLDialect

This reduced our startup time from about 100 seconds down to 12.

Solution 2

Contributing application.yml version of property setting.

spring:
  jpa:
    properties:
      hibernate:
        temp:
          use_jdbc_metadata_defaults: false

Solution 3

Problem solved using

properties.setProperty("hibernate.temp.use_jdbc_metadata_defaults", "false");

Thanks all.

Solution 4

When I point to database in AWS RDS server it takes 78 seconds. After given this configuration it takes 52 seconds.

spring:
  jpa:
    properties:
      hibernate:
        temp:
          use_jdbc_metadata_defaults: false

And after given this configuration with the above configuration it takes only 10 seconds.

spring:
  jpa:
    hibernate:
      ddl-auto: none

Solution 5

For dev environment, use the following property

spring.jpa.hibernate.ddl-auto=none

This would be a bit risky for staging and prod environment.

View more solutions

Comments

[user3170702]

The server is remote, but it takes just a few seconds to connect using pgAdmin. And the driver seems to be loaded before the problem happens (I added a bit more logging).

[Thiago Pereira]

On MacOS 10+ you can execute on Terminal scutil --set HostName "localhost". I think is an issue resolving the network host.

[Kent Bull]

This helped with part of the issue. Now something else with the HibernateSessionFactory seems to be causing a slowdown.

[Sébastien Vanmechelen]

@ThiagoPereira you saved my day ;-)

[Abdul]

Excellent, Working like a charm. Not sure if we have any side effects.