Ankur Mhatre
958b401f0f
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.
88 lines
3.7 KiB
Markdown
88 lines
3.7 KiB
Markdown
# 03 — The four phases hiding inside one number
|
||
|
||
← prev [02 — Turning instrumentation on](02-turning-instrumentation-on.md) · next → [04 — Reading the step tree](04-reading-the-step-tree.md)
|
||
|
||
---
|
||
|
||
Grouping every recorded step by name and summing **self time** (see
|
||
[chapter 04](04-reading-the-step-tree.md) for why self and not total) gives the shape of a
|
||
startup. From [`docs/output/02-startup-tree.txt`](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](06-the-classpath-scan-tax.md), 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](07-failure-modes.md)).
|
||
|
||
---
|
||
|
||
← prev [02 — Turning instrumentation on](02-turning-instrumentation-on.md) · next → [04 — Reading the step tree](04-reading-the-step-tree.md)
|