Investigate performance of 1.3.0.RC1

[philwebb]

Running a java -jar web app seems about 300-500ms slower than 1.2.x to me.

[philwebb]

Running 1.3.x with Spring 4.1.8 shows similar timings so it looks like it's a Boot issue.

[wilkinsona]

Some numbers (averages from 10 runs) for spring-boot-sample-web-freemarker:

• 1.2.7.RELEASE started in 2.461 seconds with the JVM running for 2.824 seconds.
• 1.3.0.BUILD-SNAPSHOT started in 2.729 seconds with the JVM running for 3.082 seconds.

[wilkinsona]

1.3.0 evaluates an additional 32 conditions but, looking at time spent in SpringBootCondition.matches, that only accounts for ~40ms of the time difference.

[wilkinsona]

Hacking spring.factories in spring-boot-autoconfigure so that 1.3 has (roughly) the same set of auto-configuration classes and conditions as 1.2.x still shows the same difference in startup time.

[snicoll]

The batch sample is also quite slower on master: 1.2.8.BUILD-SNAPSHOT executes around 0.12 sec while master executes around 0.14 sec.

[snicoll]

@philwebb are you sure you ran 1.3.x with Spring Framework 4.1.x? There are some basic stuff (event listener) that couldn't work so I am wondering how you managed to to work around that.

[snicoll]

Alright, something is definitely related to Spring Framework. I created an empty Spring Boot application with spring-boot-starter-web and spring-boot-starter-actuator and I started it 50 times in a loop. I then switch to the exact same code base running with Spring Framework 4.1.8.RELEASE

• master with Spring Framework: 4.2.3.BUILD-SNAPSHOT: between 27.2 and 28.1 sec
• "patched" master with Spring Framework: 4.1.8.RELEASE: between 21.1 and 23.1 sec

On master this app starts around 0.35 sec while with the patched version using Spring Framework 4.1.8.RELEASE a typical startup time is more around 0.3 sec.

[snicoll]

There is a confirmed performance regression in annotation lookup that we are currently investigating, see SPR-13621 for more details.

[snicoll]

@jhoeller has been working on some optimizations in Spring Framework and we could manage to cut those numbers a bit: From a [27.2 to 28.1 sec] range we are more around a [26.9 to 27.6 sec] range. There are more pointers in Spring Framework but I'll also start looking a bit more at boot itself (even though I haven't see any specific indication yet).

[snicoll]

So an update, testing that same app with 3 configurations: Spring Boot 1.2.8-SNAP, Spring Boot 1.3.0-SNAP (patched) with Spring Framework 4.1.8.RELEASE and finally Spring Boot 1.3.0-SNAP (using the latest Spring Framework 4.2.3-SNAP build.

1.2.8-SNAP + 4.1.8

Started SampleWebFreeMarkerApplication in 2.543 seconds (JVM running for 2.879)
Started SampleWebFreeMarkerApplication in 0.274 seconds (JVM running for 3.224)
Started SampleWebFreeMarkerApplication in 0.252 seconds (JVM running for 3.535)
Started SampleWebFreeMarkerApplication in 0.224 seconds (JVM running for 3.815)
Started SampleWebFreeMarkerApplication in 0.222 seconds (JVM running for 4.097)
Started SampleWebFreeMarkerApplication in 0.232 seconds (JVM running for 4.39)
Started SampleWebFreeMarkerApplication in 0.217 seconds (JVM running for 4.666)
Started SampleWebFreeMarkerApplication in 0.22 seconds (JVM running for 4.945)
Started SampleWebFreeMarkerApplication in 0.231 seconds (JVM running for 5.233)
Started SampleWebFreeMarkerApplication in 0.224 seconds (JVM running for 5.518)

1.3.0-SNAP (patched) + 4.1.8

Started SampleWebFreeMarkerApplication in 2.632 seconds (JVM running for 3.027)
Started SampleWebFreeMarkerApplication in 0.381 seconds (JVM running for 3.481)
Started SampleWebFreeMarkerApplication in 0.257 seconds (JVM running for 3.743)
Started SampleWebFreeMarkerApplication in 0.253 seconds (JVM running for 4.056)
Started SampleWebFreeMarkerApplication in 0.252 seconds (JVM running for 4.367)
Started SampleWebFreeMarkerApplication in 0.251 seconds (JVM running for 4.678)
Started SampleWebFreeMarkerApplication in 0.249 seconds (JVM running for 4.983)
Started SampleWebFreeMarkerApplication in 0.268 seconds (JVM running for 5.308)
Started SampleWebFreeMarkerApplication in 0.255 seconds (JVM running for 5.624)
Started SampleWebFreeMarkerApplication in 0.265 seconds (JVM running for 5.951)

1.3.0-SNAP + 4.2.3-SNAP

Started SampleWebFreeMarkerApplication in 3.012 seconds (JVM running for 3.36)
Started SampleWebFreeMarkerApplication in 0.491 seconds (JVM running for 3.921)
Started SampleWebFreeMarkerApplication in 0.449 seconds (JVM running for 4.428)
Started SampleWebFreeMarkerApplication in 0.456 seconds (JVM running for 4.942)
Started SampleWebFreeMarkerApplication in 0.411 seconds (JVM running for 5.416)
Started SampleWebFreeMarkerApplication in 0.405 seconds (JVM running for 5.883)
Started SampleWebFreeMarkerApplication in 0.387 seconds (JVM running for 6.329)
Started SampleWebFreeMarkerApplication in 0.435 seconds (JVM running for 6.824)
Started SampleWebFreeMarkerApplication in 0.472 seconds (JVM running for 7.358)
Started SampleWebFreeMarkerApplication in 0.445 seconds (JVM running for 7.863)

In case someone is interested, the Yourkit performance snapshots are also available. According to these figures, there is a ~8% increase between 1.2 and 1.3 when the Spring Framework version has not changed but that increases to up to 40% when we also switch to Spring Framework 4.2.

A few hotspots:

• Method.invoke invocation count has increased by ~30%
• lots of CPU cycles are spent in the new annotation processing stuff introduced in 4.2