asmhatre/jfr
1
0
Fork 0
Code Activity
Files
main
jfr/README.md
T
asmhatre c7eccd1db5 Add jfr-demo: JFR + Mission Control profiling of a live Spring Boot app 
Custom OrderProcessed event, CPU/allocation/lock workloads, a diagnostic
endpoint over the JVM's live FlightRecorder state, a JUnit test using the
jdk.jfr.Recording API, and nine captured recordings (flagship, mid-flight
snapshot, isolated vs concurrent threshold comparisons, and a real
dump+stop duplication bug) with their docs/output/*.txt transcripts.
2026-10-01 04:37:26 +00:00

102 lines
5.4 KiB
Markdown
Raw Permalink Blame History

# jfr-demo
Companion project for the ankurm.com post **"Java Flight Recorder and Mission
Control: Profiling a Live Spring Boot App in 20 Minutes."** A small Spring Boot
app with three deliberately bad workloads (a CPU hot method, an
allocation-heavy method, and a lock-contention scenario), one custom JFR event
for a fictional "order processed" business operation, and a diagnostic
endpoint that prints the JVM's own live Flight Recorder state.
Every number in the post comes from a file under `docs/output/`, produced by
either the JUnit test suite or a real `jcmd` + `curl` session against a
running instance of this app — see the index below.
## Versions this was built and verified against
| Component | Version | Verified against |
|---|---|---|
| JDK | 25.0.4.1 (Temurin, LTS) | `java -version`; [Adoptium](https://api.adoptium.net/v3/info/available_releases) lists 25 as `most_recent_lts` |
| Spring Boot | 4.1.1 | Maven Central directory listing, uploaded 2026-08-20 |
| JUnit | 6.0.3 (pulled in by `spring-boot-starter-test`) | `mvn dependency:tree` |
| Maven | bundled in the sandbox | `mvn -v` |
## Quickstart
```bash
# JDK 25 (or any LTS 21+; JFR itself needs nothing newer than 17)
mvn -q -B -DskipTests package
java -jar target/jfr-demo.jar &
PID=$!
# start a profiling recording
jcmd $PID JFR.start name=live settings=profile filename=/tmp/live.jfr maxsize=256m
# generate real load (see scripts/load.sh for each kind individually)
scripts/load.sh all
# stop and inspect
jcmd $PID JFR.stop name=live
jfr summary /tmp/live.jfr
jfr print --events com.ankurm.jfr.OrderProcessed /tmp/live.jfr
```
`scripts/run-all.sh` regenerates every file under `docs/output/` in one
command (it runs the test suite, then drives the full live-app capture).
`scripts/capture-jfr.sh <pid>` reproduces just the flagship recording.
`scripts/reproduce-dump-bug.sh <pid>` reproduces the dump/stop duplication
trap documented in `docs/output/09-dump-duplication-bug.txt` &mdash; do not
copy that script's pattern into real code.
## Endpoints
| Method & path | What it does | JFR event(s) it produces |
|---|---|---|
| `GET /api/cpu/fibonacci?n=38` | Naive recursive Fibonacci &mdash; a CPU hot method | `jdk.ExecutionSample` |
| `GET /api/alloc/churn?iterations=400000` | Short-lived `String`/`byte[]`/boxed-`Byte` churn | `jdk.ObjectAllocationSample` |
| `GET /api/lock/contend?workers=16&holdMillis=20` | N threads fight over one synchronized block | `jdk.JavaMonitorEnter`, `jdk.ThreadPark` |
| `GET /api/orders/process?items=3` | Simulated order processing | `com.ankurm.jfr.OrderProcessed` (custom) |
| `GET /api/jfr/recordings` | Diagnostic: lists this JVM's own live recordings | &mdash; (delete before shipping) |
| `GET /api/jfr/event-types` | Diagnostic: lists registered `com.ankurm.*` event types | &mdash; (delete before shipping) |
## Captured output index (`docs/output/`)
| File | What it proves |
|---|---|
| `01-order-event-test.txt` | The custom event, driven purely through the `jdk.jfr.Recording` Java API in a JUnit test &mdash; no server, no jcmd |
| `02-start-recording-and-diagnostics.txt` | `jcmd JFR.start`, the live `/api/jfr/recordings` diagnostic, `jcmd JFR.stop` |
| `03-hot-method-samples.txt` | Top CPU stack frames: `fibonacci()` is 63% of samples |
| `04-allocation-samples.txt` | Top allocating classes and call sites during `churnAllocations` |
| `05-lock-contention-live-demo.txt` | 15 `jdk.JavaMonitorEnter` events from one 16-worker contention burst, escalating in ~20 ms steps |
| `06-custom-event-live-demo.txt` | 23 of 60 simulated orders kept by the event's 20 ms threshold |
| `07-threshold-isolated-comparison.txt` | `settings=default` misses a 12 ms lock wait entirely; `settings=profile` catches all of it; both catch a 35 ms wait |
| `08-concurrent-recordings-shared-threshold.txt` | The same `settings=default` recording DOES catch the 12 ms wait once a second, lower-threshold recording is also active &mdash; thresholds are effectively global across concurrent recordings |
| `09-dump-duplication-bug.txt` | `JFR.dump` to a recording's own configured destination, followed by `JFR.stop`, doubles every event in the file |
| `10-final-summary.txt` | Full `jfr summary` of the clean flagship recording |
| `11-broken-event-pattern.txt` | A missing `try/finally` around `event.commit()` silently drops exactly as many events as the exceptions thrown |
## Recordings (`recordings/`)
Real, unedited `.jfr` files, small enough to commit and open yourself in JDK
Mission Control or VisualVM:
- `live-demo.jfr` &mdash; the flagship recording referenced throughout the post
- `mid-flight-snapshot.jfr` &mdash; a snapshot taken while `live-demo.jfr`'s
recording was still running, proving you can inspect without stopping
- `dump-duplication-bug.jfr` &mdash; the buggy recording from
`docs/output/09-dump-duplication-bug.txt`, kept exactly as produced
- `solo-default.jfr`, `solo-profile.jfr`, `solo-default-longhold.jfr` &mdash;
the isolated threshold comparison (`docs/output/07`)
- `compare-default.jfr`, `compare-profile.jfr` &mdash; the concurrent-recordings
comparison (`docs/output/08`)
## What to delete before shipping
`DiagnosticsController` (`/api/jfr/recordings`, `/api/jfr/event-types`) has no
business being reachable from the internet. It exists here purely so the post
and this README could show real, live Flight Recorder state instead of a
description of it.
## License
MIT, see [`LICENSE`](LICENSE).
View Git Blame Copy Permalink