0

We have a Spring Boot app and it's startup time is a disadvantage for us; it is slowing down the CI/CD process. It's startup time is ~140 seconds;

  • WebApplicationContext initialization completes in ~30 seconds
  • org.hibernate.boot.internal.MetadataImpl.getSessionFactoryBuilder -> ~30 seconds
  • DispatcherServlet initialization completes in ~60 seconds
  • And rest of the operations takes ~20 seconds.

I've researched about how to increase Spring startup time and I've read How Fast is Spring? blog and related stackoverflow posts. But, these are not helping to us since the actual problem is different. For example, only DispatcherServlet initialization completes in ~60 seconds. Therefore, I've researched about DispatcherServlet and I saw that it is completely related with Spring; just a FontController, so it should be faster than the current version.

However, while DispatcherServlet initialization I see that hibernates opens a connection and commits something. Hibernate committing takes ~50 seconds where the whole DispatcherServlet initialization ~60 seconds.

Then, I've debugged and I saw that committing happens while DispatcherServlet.initHandlerMappings() call, but I couldn't go further than this.

Do you have an idea about why DispatcherServlet initialization takes this much time?

A part from log file about DispatcherServlet initialization:

2021-04-16 14:47:12 INFO    1  DispatcherServlet | Initializing Servlet 'dispatcherServlet'
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 WARN    1  NamedQuery | Finder method public abstract java.util.List com.example.TestRepository.getTestList1(org.springframework.data.domain.Pageable) is backed by a NamedQuery but contains a Pageable parameter! Sorting delivered via this Pageable will not be applied!
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 WARN    1  NamedQuery | Finder method public abstract java.util.List com.example.TestRepository.getTestList2(org.springframework.data.domain.Pageable) is backed by a NamedQuery but contains a Pageable parameter! Sorting delivered via this Pageable will not be applied!
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:16 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:17 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:47:17 DEBUG   1  TransactionImpl | begin
2021-04-16 14:47:17 INFO    1  p6spy | #1618573637572 | took 152ms | statement | connection 1| url jdbc:p6spy:firebirdsql:localhost/8080
SELECT 1 FROM TEST_QUERY
SELECT 1 FROM TEST_QUERY;
2021-04-16 14:47:17 DEBUG   1  TransactionImpl | committing
2021-04-16 14:48:03 INFO    1  EndpointLinksResolver | Exposing 15 endpoint(s) beneath base path '/app'
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 DEBUG   1  TransactionImpl | On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2021-04-16 14:48:04 INFO    1  DispatcherServlet | Completed initialization in 52429 ms
ytWho
  • 195
  • 8
  • DEBUG logging will considerably slowdown your startup, especially for the Spring MVC part as that will log a lot of stuff. Starting the dispatcher servlet is basically starting the application, it will also trigger hibernate to do whatever it needs to do with the schema. So what is your strategy defined for `spring.jpa.hibernate.ddl-auto` or `spring.jpa.generate-ddl`. Also do you have a `schema.sql` or `data.sql`? ALl the proxying you are doing will also add overhead (I see p6spy in your URL). Also don't specify a validation query, JDBC4 has better ways to do validation. – M. Deinum Apr 16 '21 at 14:12
  • @M.Deinum 1. The performance is almost same without DEBUG logging as well. 2. Why dispatcher servlet tiggers the hibernate? couldn't find any information about it. I wonder the reason, because it is the biggest bottle-neck of the application. 3. We don't 'use spring.jpa.hibernate.ddl-auto' or 'spring.jpa.generate-ddl', so default values of the properties. 4. We don't have 'schema.sql' or 'data.sql'. 5. I'll look for proxying. 6. I'll check JDBC4 too. Thank you so much for your reply. – ytWho Apr 19 '21 at 15:19

0 Answers0