Adds spring-boot-startup-time/, the companion project for BLOG-618: a runnable Spring Boot 4.1.1 application on JDK 25 that installs BufferingApplicationStartup and FlightRecorderApplicationStartup behind a system property, and a /diag/startup endpoint that computes step self time -- the number /actuator/startup does not give you and the one that names the actual culprits. Captured under docs/output/: the step tree sorted both ways, the same startup as JFR events, a +5000-class experiment putting 0.11 ms per scanned class on the classpath scan tax, the silent truncation a 2048-step buffer performs, and JDK 25 AOT cache timings (6.93 s to 4.82 s). Post body and metadata live in post/. Moves the existing Actuator project into actuator-in-production/ so the repository holds one directory per article; the root README is now an index.
3.7 KiB
03 — The four phases hiding inside one number
← prev 02 — Turning instrumentation on · next → 04 — Reading the step tree
Grouping every recorded step by name and summing self time (see
chapter 04 for why self and not total) gives the shape of a
startup. From docs/output/02-startup-tree.txt:
self ms count step
4253.68 361 spring.beans.instantiate
1014.51 1 spring.context.config-classes.parse
402.81 1 spring.boot.application.environment-prepared
160.39 1 spring.boot.webserver.create
153.07 1 spring.boot.application.started
113.74 1 spring.context.refresh
95.72 1 spring.data.repository.proxy
51.50 6 spring.beans.smart-initialize
43.85 1 spring.data.repository.scanning
Four phases account for essentially all of it, and they respond to entirely different fixes.
1. Bean instantiation — spring.beans.instantiate
361 steps, 4.25 s. This is constructors, @PostConstruct, FactoryBean.getObject() and
proxy creation. It is where your own code lives, and it is the only phase you can fix by
changing application code.
Note what is not a separate step: @PostConstruct has no step of its own, so a cache
warm shows up inside the owning bean's spring.beans.instantiate. tariffCacheWarmer in
this repository spends all of its 504 ms in @PostConstruct and none in its constructor,
and the timeline cannot tell you which.
2. Configuration class parsing — spring.context.config-classes.parse
One step, 1.01 s, and under JFR it carries a tag naming the cost driver:
PT1.176668418S spring.context.config-classes.parse classCount=130,
130 configuration classes. This step is component scanning plus @Conditional evaluation
across every auto-configuration your classpath drags in. It is proportional to classes
inspected, not to beans created — see chapter 06, where
adding 5,000 classes that are not beans at all still adds half a second here.
3. Environment preparation — spring.boot.application.environment-prepared
403 ms before any bean exists. Property sources, profile resolution, config data imports. Cheap to ignore and impossible to tune from application code, but it explains why "the app does nothing for the first half second".
4. Everything else
spring.boot.webserver.create (160 ms), the Spring Data repository steps (~150 ms across
five step names), spring.beans.smart-initialize. Individually small; collectively a
second. Spring Data's contribution scales with the number of repository interfaces and
derived query methods, since each one is parsed and proxied.
The step names, in the order they nest
spring.boot.application.starting
spring.boot.application.environment-prepared
spring.boot.application.context-prepared
spring.context.refresh
├── spring.context.beandef-registry.post-process
│ └── spring.context.config-classes.parse ← scanning + conditions
├── spring.context.bean-factory.post-process
├── spring.context.beans.post-process
│ └── spring.beans.instantiate (×N, nested by dependency)
└── spring.boot.webserver.create
spring.boot.application.started
spring.boot.application.ready
A step is recorded when it ends, which is why the outermost ones appear last in the timeline — and why they are the first casualties of a full buffer (chapter 07).
← prev 02 — Turning instrumentation on · next → 04 — Reading the step tree