eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 721 forks source link

Start-up for Spring Boot Applications using Apache Camel much slower than Hotspot #14764

Open PascalSchumacher opened 2 years ago

PascalSchumacher commented 2 years ago

Java -version output

openjdk version "11.0.14.1" 2022-02-08
IBM Semeru Runtime Open Edition 11.0.14.1 (build 11.0.14.1+1)
Eclipse OpenJ9 VM 11.0.14.1 (build openj9-0.30.1, JRE 11 Windows 10 amd64-64-Bit Compressed References 20220210_305 (JIT enabled, AOT enabled)
OpenJ9   - 9dccbe076
OMR      - 56c3376ba
JCL      - 5c423dacd0 based on jdk-11.0.14.1+1)

Java 17, Linux and older Java 11 versions are also affected.

Summary of problem

We noticed that Spring Boot Applications using Apache Camel (especially those using EndpointRouteBuilder) start much slower on OpenJ9 than on Hotspot. It does not matter if it is Java 11 or 17, Linux or Windows, a resource constrained docker container (2 CPUs) or a developer laptop with 6 CPUs. OpenJ9 is always significantly slower than Hotspot.

As we can not share the real code we created a simplified example project which allows easy replication of this issue: https://github.com/PascalSchumacher/camel-springboot-openj9-slow-startup

Start-up time using Hotspot:

Started Application in 2.95 seconds (JVM running for 3.286)

Start-up time using OpenJ9:

Started Application in 6.206 seconds (JVM running for 6.964)
Started Application in 4.347 seconds (JVM running for 4.637)
Started Application in 4.216 seconds (JVM running for 4.479)

The main difference (according to http://localhost:8080/actuator/startup in the example application) is that it takes significantly longer to initiate beans extending EndpointRouteBuilder (there are usually a lot of these in applications using Apache Camel) on OpenJ9. Hotspot takes e.g. PT0.0269295S to instantiate the route10 bean of the example project, while OpenJ9 takes PT0.298307S

By the way: Thank you very much for developing OpenJ9! 👍

Edit: EndpointRouteBuilder extends EndpointBuilderFactory which extends 344 interfaces, maybe that causes OpenJ9 to be slow?

Second Edit: The extension of the many interfaces seems to be the reason. As a workaround I created my own RouteBuilder extending only the interfaces currently in use. When I use that start-up of the app takes the same amount of time with OpenJ9 and Hotspot.

pshipton commented 2 years ago

@vijaysun-omr fyi

Thihup commented 2 years ago

@PascalSchumacher Could you try running with the -Xshareclasses:name=myspringapp -Xscmx500m command line flag twice? Probably it should improve the startup time after the first run

PascalSchumacher commented 2 years ago

@Thihup Thanks!

I tried it with a "real" application:

OpenJ9 plain:

Started APP in 23.372 seconds (JVM running for 23.984)
Started APP in 22.925 seconds (JVM running for 23.433)

OpenJ9 -Xshareclasses:name=myspringapp -Xscmx500m:

Started APP in 21.342 seconds (JVM running for 22.024)
Started APP in 20.026 seconds (JVM running for 20.513)

Hotspot:

Started APP in 12.879 seconds (JVM running for 13.603)

OpenJ9 java -version output:

openjdk version "17.0.1" 2021-10-19
IBM Semeru Runtime Open Edition 17.0.1.0 (build 17.0.1+12)
Eclipse OpenJ9 VM 17.0.1.0 (build openj9-0.29.1, JRE 17 Windows 10 amd64-64-Bit Compressed References 20211207_55 (JIT enabled, AOT enabled)
OpenJ9   - 7d055dfcb
OMR      - e30892e2b
JCL      - fc67fbe50a0 based on jdk-17.0.1+12)

I should have mentioned that I already experimented with different class data sharing options (and/or aot options) and quickstart but saw only minimal differences.

Bromarv commented 2 years ago

@PascalSchumacher - did you tried with a "pre-warming" SCC?

I used Semeru 11.0.16.1 and 17.0.4.1:

Semeru 11: 2022-10-06 15:13:07.295 INFO 1 --- [ecutor-thread-6] sample.camel.Application : Started Application in 8.435 seconds (JVM running for 11.198) --> events 10 duration: "PT0.06710205S"

Semeru 17: 2022-10-06 16:35:47.872 INFO 1 --- [ecutor-thread-2] sample.camel.Application : Started Application in 9.364 seconds (JVM running for 12.288)

--> events 10 duration: "PT0.074021547S"