Query validation significantly slows down application startup [DATAJPA-1370]

[spring-projects-issues]

Сергей Цыпанов opened DATAJPA-1370 and commented

Having dozens of interfaces extending JpaRepository and several hundreds of methods annotated with @Query it takes application significant type to start up.

I think there could be an option to disable validation e.g. for tests.

Also SimpleJpaQuery::validateQuery can be improved: e.g. we should compute error message only if necessary

---

2 votes, 4 watchers

[spring-projects-issues]

Oliver Drotbohm commented

Care to add some numbers to back "significantly slows down"? We have quite some extensive benchmarks in Spring Boot that indicate that Spring Data JPA only adds negligible bootstrap overhead compared e.g. to the native Hibernate bootstrap time.

I'll use this ticket to make sure we avoid the String.format(…) although I'd also doubt it has significant effect until I see some numbers 🙃

[spring-projects-issues]

Сергей Цыпанов commented

Sure, currently my metrics are approximate, right now I try to create sime reliable benchmark.

We have a project with Spring Data JPA under Spring Boot. Once someone add a dependency spring-boot-starter-data-ldap into a list of dependencies and we immediately spotted an increase in startup time. Debugging demonstrated that when Spring Boot initialized its context all repositories extending JpaRepository we treated as both JPA and LDAP repositories and query validation occurred. I've excluded spring-boot-starter-data-ldap from dependencies and turned off ldap repositories by adding spring.ldap.repositories.enabled: false into application.yml. Startup time reduction was about 15 seconds, I think this is the time wasted onto queries validation for ldap repos. Validation for JPA repos should cost us the same.

I understand this metrics is quite naive, but currently it's all I have

[spring-projects-issues]

Сергей Цыпанов commented

P.S. On your project we have 93 repository interfaces extending JpaRepository and 118 @Query methods

[spring-projects-issues]

Oliver Drotbohm commented

Thanks, Сергей Цыпанов. That's very helpful information. What puzzles me a bit is that having two Spring Data modules on the classpath actually triggers a strict repository scanning mode which assigns a repository to a store by inspecting it closer (the repository base interface, annotations on the entity class managed etc.). I.e. it's kind of impossible that an interface is "assigned" to both stores, mostly because both store implementations would end up using the same bean name for the bean definitions registered and thus only one end up surviving as one would override the other.

I just checked Spring Data LDAP and it seems to have all things in place to take part in this more strict mode (ultimately it's these two methods in LdapConfigurationExtension). If you set the log level for Spring Data to debug you should actually see which store module a repository was assigned to. Also, the store implementations shouldn't even find queries to validate as the @Query annotation is store specific.

We have an example for using both MongoDB and JPA in our examples repository. You should be able to produce similar output in you case. Does that help diagnosing the issue?

[spring-projects-issues]

Сергей Цыпанов commented

Oliver Drotbohm
I finally created a benchmark to measure how much does it cost to validate one single query. To my surprise it only takes 2 us to validate a simple HQL query. However, there are two circumstances making me think this issue requires deeper investigation:

1. there is only a few entities in domain model of a benchmark
2. query is the simplest one possible
3. plain Spring Core + Spring Data JPA (not Spring Boot starters) used

Getting back to you last comment:

• strict repository scanning mode is indeed seems to be turned on in my case, at least I've got this message in log twice:

Multiple Spring Data modules found, entering strict repository configuration mode!

• in addition there are messages from

Spring Data LDAP - Could not safely identify store assignment for repository candidate interface ....

Those messages count is the same as number of interfaces inheriting JpaRepository, but unlike the multi-store example you provided log messages are coming only for LDAP, not for both LDAP and JPA, so the behaviour is slightly different.

I cannot attach sources of the project, but I'll try to build one for demonstration having exactly the same dependencies and configuration.

[spring-projects-issues]

Сергей Цыпанов commented

Not sure, but it seems I've got high-level understanding of what happened.

In multi-store example both TreasureRepository and PersonRepository extend CrudRepository i.e. top-level interface in inheritance hierarchy. This is why both spring-boot-starter-data-mongodb and spring-boot-starter-data-jpa pick them up.

But in my case all our repositories extend JpaRepository and should be picket only by spring-boot-starter-data-jpa, not spring-boot-starter-data-ldap. What happens instead is that spring-boot-starter-data-ldap finds interfaces extending JpaRepository and tries to process them. As for me this is wrong and must be changed, as a child of JpaRepository by its nature is bound to JPA, not LDAP.

P.S. Demonstration example fails to start when TreasureRepository's parent is changed from CrudRepository to JpaRepository:

2018-07-07 20:49:51.710 ERROR 6260 --- [  restartedMain] o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'repositorySearchController' defined in URL [jar:file:/G:/.m2/repository/org/springframework/data/spring-data-rest-webmvc/3.0.8.RELEASE/spring-data-rest-webmvc-3.0.8.RELEASE.jar!/org/springframework/data/rest/webmvc/RepositorySearchController.class]: Unsatisfied dependency expressed through constructor parameter 0; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'pagedResourcesAssembler' defined in class path resource [org/springframework/data/rest/webmvc/config/RepositoryRestMvcConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.web.PagedResourcesAssembler]: Factory method 'pagedResourcesAssembler' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'pageableResolver' defined in class path resource [org/springframework/data/rest/webmvc/config/RepositoryRestMvcConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.web.PageableHandlerMethodArgumentResolver]: Factory method 'pageableResolver' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sortResolver' defined in class path resource [org/springframework/data/rest/webmvc/config/RepositoryRestMvcConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.web.SortHandlerMethodArgumentResolver]: Factory method 'sortResolver' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'repositoryRestConfiguration' defined in class path resource [org/springframework/data/rest/webmvc/config/RepositoryRestMvcConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.rest.core.config.RepositoryRestConfiguration]: Factory method 'repositoryRestConfiguration' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'repositories' defined in class path resource [org/springframework/data/rest/webmvc/config/RepositoryRestMvcConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.repository.support.Repositories]: Factory method 'repositories' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'treasureRepository': Invocation of init method failed; nested exception is org.springframework.data.mapping.PropertyReferenceException: No property deleteAllInBatch found for type Treasure!
	at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:732) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:197) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1276) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1133) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:503) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:317) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:315) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:760) ~[spring-beans-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:869) ~[spring-context-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550) ~[spring-context-5.0.7.RELEASE.jar:5.0.7.RELEASE]
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:140) ~[spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:759) [spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:395) [spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:327) [spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1255) [spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1243) [spring-boot-2.0.3.RELEASE.jar:2.0.3.RELEASE]
	at example.springdata.multistore.Application.main(Application.java:32) [classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_162]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_162]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_162]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_162]
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49) [spring-boot-devtools-2.0.3.RELEASE.jar:2.0.3.RELEASE]

[spring-projects-issues]

andrew-landsverk-win commented

I am also seeing weirdness with both data-cassandra and data-jpa on the classpath. I am strictly using JpaRepository and CassandraRepository as my base classes, yet spring-data-cassandra is insisting on checking the JpaRepository repositories and asking me to use cassandra specific interfaces even though these repositories are for Spring Data JPA. The application starts and loads fine, but these info messages are incorrect and misleading in my opinion, but maybe it's a setup issue on my end?

[spring-projects-issues]

Oliver Drotbohm commented

The repository base interface is a quite unfortunate differentiator for the stores as we effectively cannot teach LDAP about all potential other Spring Data stores to ignore. To it, the repository is extending a Spring Data interface (as JpaRepository extends CrudRepository) and thus is just a potential candidate interface. Which means that each store will at least have to have an initial look at the interface and then decide what to do with it.

In single store mode it will just use it straight away. In strict mode, i.e. if multiple stores are on the classpath, the repository should only be processed completely if it either implements the store specific repository or the domain type managed by the repository is annotated with a store specific annotation, @Entry in the case of LDAP. This is implemented in RepositoryConfigurationExtensionSupport.isStrictRepositoryCandidate(…) which is called from RCES.getRepositoryConfigurations(…) before the configuration for the repository is added for instantiation.

I guess it makes sense to add that if you see the message that a repository has been dropped by a particular store, no inspection of the repository or queries defined in it has been performed yet. That message is the result of a pure assignability / annotation presence check (again see RCES.isStrictRepositoryCandidate(…)). If the repository is making it into the query validation stage, it cannot be dropped anymore and every failure, invalid query or the like would result in an exception and a failure for the application to start.

Сергей Цыпанов – I cannot follow your statements. The example linked to does not contain the mentioned repositories.

Getting back to you last comment:

• strict repository scanning mode is indeed seems to be turned on in my case, at least I've got this message in log twice:

Multiple Spring Data modules found, entering strict repository configuration mode!

• in addition there are messages from

Spring Data LDAP - Could not safely identify store assignment for repository candidate interface ....

Those messages count is the same as number of interfaces inheriting JpaRepository, but unlike the multi-store example you provided log messages are coming only for LDAP, not for both LDAP and JPA, so the behaviour is slightly different.

This is exactly what's expected if all your repositories are JPA repositories. LDAP would have to have a look at the JPA ones and signal that it's not gonna process them. JPA doesn't have to issue these logs as it's not dropping the repositories but actually taking them forward to eventually become Spring Beans.

If anyone of you can provide a minimal, reproducing project, that'd be helpful. Or modify one of the Spring Data examples projects to show the problem

[amitlpande]

Is there any update on this work?
We too have a project with large number of JPA repository beans and the query validation is slowing down the application startup.
Is there any way to provide a custom SimpleJpaQuery (by extending this class) for testing purposes and see the difference?

https://github.com/spring-projects/spring-data-jpa/blob/main/spring-data-jpa/src/main/java/org/springframework/data/jpa/repository/query/SimpleJpaQuery.java

Thanks,
Amit