Optimize startup time: condition processing #7573

dsyer · 2016-12-06T09:21:46Z

Benchmark data from here https://github.com/dsyer/spring-boot-startup-bench suggest that condition processing is noticeable at startup time (not dominating it, but it's non-negligible, amounting to a few hundred ms depending on hardware). The most startling evidence is the "minimal" sample app from that project where @EnableAutoConfiguration is disabled and startup time improves dramatically.

One way this could maybe be fixed is to break up spring-boot-autoconfigure into separate modules, so that only the conditions you need to be evaluated will be, for any given app, based on the classpath.

The text was updated successfully, but these errors were encountered:

philwebb · 2016-12-06T17:49:43Z

Another option that we've discussed before is to somehow pre-determine @ConditionalOnClass results at compile time.

philwebb · 2017-01-12T14:08:02Z

See also #7939

philwebb · 2017-01-21T19:01:22Z

Some experimental code is here.

Running petclinic locally in the IDE with 1.5.0.RC1

2017-01-20 23:01:54.080  INFO 70090 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 8.016 seconds (JVM running for 8.433)
2017-01-20 23:02:11.588  INFO 70118 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 7.952 seconds (JVM running for 8.412)
2017-01-20 23:02:29.601  INFO 70143 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 8.178 seconds (JVM running for 8.601)

And with the experimental branch (including the other optimizations we've already pushed)

2017-01-21 07:44:36.103  INFO 84153 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 6.695 seconds (JVM running for 7.092)
2017-01-21 07:45:04.225  INFO 84192 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 6.777 seconds (JVM running for 7.187)
2017-01-21 07:45:31.196  INFO 84232 --- [  restartedMain] o.s.s.petclinic.PetClinicApplication     : Started PetClinicApplication in 6.665 seconds (JVM running for 7.073)

philwebb · 2017-01-21T19:02:29Z

And with a hacked version of the benchmarks to support 1.5.0

Benchmark                                      Mode  Cnt   Score   Error  Units
ConfigServerBenchmark.devtoolsRestart          avgt   10   1.339 ± 0.114   s/op
ConfigServerBenchmark.explodedJarMain          avgt   10   3.768 ± 0.068   s/op
ConfigServerBenchmark.fatJar138                avgt   10   4.677 ± 0.062   s/op
ConfigServerBenchmark.fatJar142                avgt   10   4.506 ± 0.064   s/op
ConfigServerBenchmark.fatJar150                avgt   10   4.154 ± 0.069   s/op
ConfigServerBenchmark.fatJar150RC1             avgt   10   4.565 ± 0.041   s/op
JsaBenchmark.sharedClasses                     avgt   10   4.724 ± 0.066   s/op
JsaBenchmark.thinMain                          avgt   10   5.540 ± 0.065   s/op
MinimalBenchmark.explodedJarMain               avgt   10   2.005 ± 0.035   s/op
MinimalBenchmark.fatJar                        avgt   10   2.464 ± 0.035   s/op
PetclinicBenchmark.devtoolsRestart             avgt   10   1.987 ± 0.129   s/op
PetclinicBenchmark.exploded150JarMain          avgt   10   5.750 ± 0.112   s/op
PetclinicBenchmark.exploded150rc1JarMain       avgt   10   6.047 ± 0.097   s/op
PetclinicBenchmark.explodedJarMain             avgt   10   5.932 ± 0.067   s/op
PetclinicBenchmark.fatJar                      avgt   10   8.510 ± 0.095   s/op
PetclinicBenchmark.fatJar150                   avgt   10   8.456 ± 0.329   s/op
PetclinicBenchmark.fatJar15rc1                 avgt   10   8.763 ± 0.299   s/op
PetclinicBenchmark.noverify                    avgt   10   7.487 ± 0.079   s/op
ShadedBenchmark.explodedShadedMain             avgt   10   7.147 ± 1.496   s/op
ShadedBenchmark.shaded                         avgt   10  10.107 ± 0.962   s/op
SpringBoot138Benchmark.explodedJarLauncher     avgt   10   3.546 ± 0.178   s/op
SpringBoot138Benchmark.explodedJarMain         avgt   10   2.460 ± 0.097   s/op
SpringBoot138Benchmark.fatJar                  avgt   10   3.292 ± 0.110   s/op
SpringBoot142Benchmark.explodedJarLauncher     avgt   10   3.641 ± 0.100   s/op
SpringBoot142Benchmark.explodedJarMain         avgt   10   2.661 ± 0.043   s/op
SpringBoot142Benchmark.fatJar                  avgt   10   3.493 ± 0.142   s/op
SpringBoot150Benchmark.explodedJarLauncher     avgt   10   3.362 ± 0.092   s/op
SpringBoot150Benchmark.explodedJarMain         avgt   10   2.508 ± 0.043   s/op
SpringBoot150Benchmark.fatJar                  avgt   10   3.173 ± 0.114   s/op
SpringBoot150RC1Benchmark.explodedJarLauncher  avgt   10   3.968 ± 0.316   s/op
SpringBoot150RC1Benchmark.explodedJarMain      avgt   10   2.796 ± 0.149   s/op
SpringBoot150RC1Benchmark.fatJar               avgt   10   3.546 ± 0.054   s/op
SpringBootThinBenchmark.basic138Thin           avgt   10   2.947 ± 0.889   s/op
SpringBootThinBenchmark.basic142Thin           avgt   10   2.950 ± 0.056   s/op
SpringBootThinBenchmark.petclinicThin          avgt   10   6.399 ± 0.514   s/op

philwebb · 2017-01-21T19:05:22Z

RC1 comparisons:

Name	Experimental	RC1
ConfigServerBenchmark.fatJar	4.154	4.565
PetclinicBenchmark.fatJar	8.456	8.763
PetclinicBenchmark.exploded	5.750	6.047

philwebb · 2017-01-21T19:09:20Z

Also worth nothing that the filtering code runs in the following time:

Filtered 68 auto configuration class in 51 ms

After that's run it's pretty much as if those auto-configuration classes were never there.

philwebb · 2017-01-22T06:41:18Z

There's one flaw with the current implementation. We need to store @AutoConfigureBefore/@AutoConfigureAfter and @Order annotation data otherwise the sorting fails.

wilkinsona · 2017-01-22T08:28:15Z

The experimental code that fills in the outcomes isn't thread-safe. There's no guarantee that outcomes filled in by the background thread will be visible to the main thread. Using an AtomicReferenceArray would correct that. I realise we get another go for anything that's missed but it'd be interesting to see the effect of making it thread-safe. It may remove some duplicate processing.

philwebb · 2017-01-23T07:40:56Z

@wilkinsona Thanks Andy! I've pushed updated code here. It should fix that and the ordering issue.

dsyer · 2017-01-23T10:08:41Z

I don't see such dramatic improvements in the benchmark times, but my hardware is faster, so maybe the difference is minimized, or maybe the thread safety had an impact.

Name	Experimental	Normal Snapshots
ConfigServerBenchmark.fatJar	2.706	2.790
PetclinicBenchmark.fatJar	4.801	5.042
PetclinicBenchmark.exploded	3.412	3.573

philwebb · 2017-01-23T17:21:37Z

@dsyer Guess I need an upgrade, you're about 3 seconds faster than me to begin with! What hardware are you using?

Update `OnClassCondition` to use its own `isPresent` rather than using `ClassUtils.isPresent`. Using our own implementation saves a few cycles since we never need to check for native types, and we don't support nested class references specified in the non `$` notation. See spring-projectsgh-7573

Update `OnBeanCondition` to no longer call `ReflectionUtils` when deducing the bean method return type. Since Spring Framework 4.2 the return type has been directly available from `MethodMetadata`. See spring-projectsgh-7573

Update `AutoConfigurationImportSelector` so that exclude properties are loaded without invoking a `DataBinder`. This optimization helps to improve application startup time. See spring-projectsgh-7573

Optimize OnEnabledResourceChainCondition by removing the DataBinder. Properties are now read directly from the Environment. See spring-projectsgh-7573

Add an annotation processor that generates properties files for certain auto-configuration class annotations. Currently attribute values from @AutoConfigureOrder, @AutoConfigureBefore, @AutoConfigureAfter and @ConditionalOnClass annotations are stored. The properties file will allow optimizations to be added in the `spring-boot-autoconfigure` project. Primarily by removing the need to ASM parse as many `.class` files. See spring-projectsgh-7573

Add AutoConfigurationMetadata interface and a an internal loader that allows easy access to data written by `spring-boot-configure-processor`. See spring-projectsgh-7573

Optimize `AutoConfigurationSorter` by used properties generated by the annotation processor whenever possible. The removes the need for each candidate class to be ASM parsed just to access the order annotations. See spring-projectsgh-7573

Add `AutoConfigurationImportFilter` strategy interface which can be used to filter auto-configuration candidates before they are loaded. See spring-projectsgh-7573

Update OnClassCondition to implement AutoConfigurationImportFilter so that auto-configuration candidates can be filtered early. The optimization helps to improve application startup time by reducing the number of classes that are loaded. See spring-projectsgh-7573

Add an annotation processor that generates properties files for certain auto-configuration class annotations. Currently attribute values from @AutoConfigureOrder, @AutoConfigureBefore, @AutoConfigureAfter and @ConditionalOnClass annotations are stored. The properties file will allow optimizations to be added in the `spring-boot-autoconfigure` project. Primarily by removing the need to ASM parse as many `.class` files. See gh-7573

Add AutoConfigurationMetadata interface and a an internal loader that allows easy access to data written by `spring-boot-configure-processor`. See gh-7573

Optimize `AutoConfigurationSorter` by used properties generated by the annotation processor whenever possible. The removes the need for each candidate class to be ASM parsed just to access the order annotations. See gh-7573

Add `AutoConfigurationImportFilter` strategy interface which can be used to filter auto-configuration candidates before they are loaded. See gh-7573

Update OnClassCondition to implement AutoConfigurationImportFilter so that auto-configuration candidates can be filtered early. The optimization helps to improve application startup time by reducing the number of classes that are loaded. See gh-7573

philwebb · 2017-01-24T07:49:36Z

Latest timings for me:

ConfigServerBenchmark.devtoolsRestart          avgt   10  1.357 ± 0.065   s/op
ConfigServerBenchmark.explodedJarMain          avgt   10  3.767 ± 0.038   s/op
ConfigServerBenchmark.fatJar138                avgt   10  4.670 ± 0.068   s/op
ConfigServerBenchmark.fatJar142                avgt   10  4.492 ± 0.080   s/op
ConfigServerBenchmark.fatJar150                avgt   10  4.119 ± 0.074   s/op
ConfigServerBenchmark.fatJar150RC1             avgt   10  4.555 ± 0.133   s/op
JsaBenchmark.sharedClasses                     avgt   10  0.126 ± 0.008   s/op
JsaBenchmark.thinMain                          avgt   10  0.117 ± 0.011   s/op
MinimalBenchmark.explodedJarMain               avgt   10  2.027 ± 0.068   s/op
MinimalBenchmark.fatJar                        avgt   10  2.468 ± 0.037   s/op
PetclinicBenchmark.devtoolsRestart             avgt   10  2.044 ± 0.072   s/op
PetclinicBenchmark.exploded150JarMain          avgt   10  5.703 ± 0.126   s/op
PetclinicBenchmark.exploded150rc1JarMain       avgt   10  6.065 ± 0.105   s/op
PetclinicBenchmark.explodedJarMain             avgt   10  6.015 ± 0.224   s/op
PetclinicBenchmark.fatJar                      avgt   10  8.557 ± 0.108   s/op
PetclinicBenchmark.fatJar150                   avgt   10  8.307 ± 0.080   s/op
PetclinicBenchmark.fatJar15rc1                 avgt   10  8.568 ± 0.103   s/op
PetclinicBenchmark.noverify                    avgt   10  7.533 ± 0.137   s/op
ShadedBenchmark.explodedShadedMain             avgt   10  7.312 ± 0.436   s/op
ShadedBenchmark.shaded                         avgt   10  9.615 ± 0.127   s/op
SpringBoot138Benchmark.explodedJarLauncher     avgt   10  3.545 ± 0.074   s/op
SpringBoot138Benchmark.explodedJarMain         avgt   10  2.418 ± 0.044   s/op
SpringBoot138Benchmark.fatJar                  avgt   10  3.252 ± 0.045   s/op
SpringBoot142Benchmark.explodedJarLauncher     avgt   10  3.629 ± 0.077   s/op
SpringBoot142Benchmark.explodedJarMain         avgt   10  2.656 ± 0.045   s/op
SpringBoot142Benchmark.fatJar                  avgt   10  3.423 ± 0.047   s/op
SpringBoot150Benchmark.explodedJarLauncher     avgt   10  3.257 ± 0.034   s/op
SpringBoot150Benchmark.explodedJarMain         avgt   10  2.453 ± 0.050   s/op
SpringBoot150Benchmark.fatJar                  avgt   10  3.079 ± 0.045   s/op
SpringBoot150RC1Benchmark.explodedJarLauncher  avgt   10  3.690 ± 0.045   s/op
SpringBoot150RC1Benchmark.explodedJarMain      avgt   10  2.751 ± 0.039   s/op
SpringBoot150RC1Benchmark.fatJar               avgt   10  3.537 ± 0.054   s/op
SpringBootThinBenchmark.basic138Thin           avgt   10  2.881 ± 0.041   s/op
SpringBootThinBenchmark.basic142Thin           avgt   10  3.099 ± 0.056   s/op
SpringBootThinBenchmark.petclinicThin          avgt   10  6.539 ± 0.170   s/op

philwebb · 2017-01-24T07:50:33Z

I think this is going to be about as good as it gets for the 1.x line. We should do some more profiling towards the end of 2.0

dsyer · 2017-01-25T09:28:48Z

I updated the benchmarks with new tests for Spring Boot 1.5.

There are a few improvements in Spring Boot 1.5 that affect startup time
(mainly to do with configuration processing). Here are some
highlighted results, where "latest" means Pet Clinic with Boot 1.5:

Benchmark                                   Mode  Cnt  Score   Error  Units
ConfigServerBenchmark.fatJar138             avgt   10  2.959 ± 0.082   s/op
ConfigServerBenchmark.fatJar142             avgt   10  2.786 ± 0.078   s/op
ConfigServerBenchmark.fatJar150             avgt   10  2.668 ± 0.084   s/op
SpringBoot138Benchmark.explodedJarLauncher  avgt   10  2.202 ± 0.111   s/op
SpringBoot138Benchmark.explodedJarMain      avgt   10  1.516 ± 0.087   s/op
SpringBoot138Benchmark.fatJar               avgt   10  2.024 ± 0.068   s/op
SpringBoot142Benchmark.explodedJarLauncher  avgt   10  2.210 ± 0.061   s/op
SpringBoot142Benchmark.explodedJarMain      avgt   10  1.649 ± 0.089   s/op
SpringBoot142Benchmark.fatJar               avgt   10  2.138 ± 0.081   s/op
SpringBoot150Benchmark.explodedJarLauncher  avgt   10  2.210 ± 0.078   s/op
SpringBoot150Benchmark.explodedJarMain      avgt   10  1.664 ± 0.085   s/op
SpringBoot150Benchmark.fatJar               avgt   10  2.128 ± 0.112   s/op
PetclinicBenchmark.devtoolsRestart          avgt   10  1.116 ± 0.070   s/op
PetclinicBenchmark.explodedJarMain          avgt   10  3.469 ± 0.069   s/op
PetclinicBenchmark.fatJar                   avgt   10  5.003 ± 0.350   s/op
PetclinicBenchmark.noverify                 avgt   10  4.358 ± 0.113   s/op
PetclinicLatestBenchmark.devtoolsRestart    avgt   10  1.056 ± 0.067   s/op
PetclinicLatestBenchmark.explodedJarMain    avgt   10  3.441 ± 0.106   s/op
PetclinicLatestBenchmark.fatJar             avgt   10  4.787 ± 0.112   s/op
PetclinicLatestBenchmark.noverify           avgt   10  4.289 ± 0.070   s/op

The configserver benefits by a few hundred millseconds. The vanilla
demo (we plus actuator) interstingly does not. The Pet Clinic also
gets a couple of hundred milliseconds boost, but not so much in the
exploded jar case (which mimic what people get in the IDE).

philwebb added the for-team-meeting label Dec 6, 2016

philwebb added the for: dave label Jan 10, 2017

philwebb added priority: high type: enhancement A general enhancement and removed for: dave labels Jan 12, 2017

snicoll added for: team-meeting and removed for: team-call labels Jan 16, 2017

philwebb added this to the 1.5.0 milestone Jan 24, 2017

philwebb self-assigned this Jan 24, 2017

philwebb added a commit to philwebb/spring-boot that referenced this issue Jan 24, 2017

Optimize OnEnabledResourceChainCondition

ccf964e

Optimize OnEnabledResourceChainCondition by removing the DataBinder. Properties are now read directly from the Environment. See spring-projectsgh-7573

philwebb added a commit that referenced this issue Jan 24, 2017

Add AutoConfigurationMetadata abstraction

1cbda9b

Add AutoConfigurationMetadata interface and a an internal loader that allows easy access to data written by `spring-boot-configure-processor`. See gh-7573

philwebb added a commit that referenced this issue Jan 24, 2017

Add AutoConfigurationImportFilter support

20a20b7

Add `AutoConfigurationImportFilter` strategy interface which can be used to filter auto-configuration candidates before they are loaded. See gh-7573

philwebb closed this as completed Jan 24, 2017

wilkinsona mentioned this issue Sep 26, 2017

Improve startup time : save the auto-configuration discovery result #10426

Closed

wilkinsona mentioned this issue Dec 19, 2018

Look for optimizations in AutoConfigurationImportSelector #15495

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Optimize startup time: condition processing #7573

Optimize startup time: condition processing #7573

dsyer commented Dec 6, 2016 •

edited

Loading

philwebb commented Dec 6, 2016 •

edited by dsyer

Loading

philwebb commented Jan 12, 2017

philwebb commented Jan 21, 2017

philwebb commented Jan 21, 2017

philwebb commented Jan 21, 2017 •

edited

Loading

philwebb commented Jan 21, 2017 •

edited

Loading

philwebb commented Jan 22, 2017

wilkinsona commented Jan 22, 2017

philwebb commented Jan 23, 2017

dsyer commented Jan 23, 2017 •

edited

Loading

philwebb commented Jan 23, 2017

philwebb commented Jan 24, 2017

philwebb commented Jan 24, 2017

dsyer commented Jan 25, 2017 •

edited by philwebb

Loading

Optimize startup time: condition processing #7573

Optimize startup time: condition processing #7573

Comments

dsyer commented Dec 6, 2016 • edited Loading

philwebb commented Dec 6, 2016 • edited by dsyer Loading

philwebb commented Jan 12, 2017

philwebb commented Jan 21, 2017

philwebb commented Jan 21, 2017

philwebb commented Jan 21, 2017 • edited Loading

philwebb commented Jan 21, 2017 • edited Loading

philwebb commented Jan 22, 2017

wilkinsona commented Jan 22, 2017

philwebb commented Jan 23, 2017

dsyer commented Jan 23, 2017 • edited Loading

philwebb commented Jan 23, 2017

philwebb commented Jan 24, 2017

philwebb commented Jan 24, 2017

dsyer commented Jan 25, 2017 • edited by philwebb Loading

dsyer commented Dec 6, 2016 •

edited

Loading

philwebb commented Dec 6, 2016 •

edited by dsyer

Loading

philwebb commented Jan 21, 2017 •

edited

Loading

philwebb commented Jan 21, 2017 •

edited

Loading

dsyer commented Jan 23, 2017 •

edited

Loading

dsyer commented Jan 25, 2017 •

edited by philwebb

Loading