jcmd and the jfr command-line tool while it runs. Every number below comes from a file committed in the companion repository, either a JUnit test’s own transcript or a real jcmd + curl session against the running app — see its captured-output index for the full list.
Versions this was built and verified against. Temurin JDK 25.0.4.1 (LTS) — JFR itself needs nothing newer than JDK 17, this is just what the sandbox had. Spring Boot 4.1.1. JUnit 6.0.3 (pulled in byspring-boot-starter-test). JDK Mission Control 9.1.2 is the current GUI build from jdk.java.net/jmc — every transcript in this post was produced by thejfrcommand-line tool andjcmdinstead, because that is what a headless build sandbox has, and it prints the identical events JMC renders as charts. The recordings themselves are committed under recordings/ in this repo — openlive-demo.jfryourself in JMC for the GUI view this title promises.
What Flight Recorder actually is: an always-on recorder, not a profiler you attach
The thing to unlearn first: JFR is not a tool you turn on when something goes wrong. The JVM is generating events — a method got sampled on CPU, an object got allocated, a thread waited for a monitor, a GC pause happened — continuously, whether or not anyone is listening. A recording does not add instrumentation to make these events exist; it is a filter that decides which already-happening events get kept, and for how long. That distinction is why starting a recording on a live, already-running process costs so little: there is no bytecode to reweave, no agent to attach, no restart. You are turning on a tap, not installing plumbing.jdk.ExecutionSample, jdk.ObjectAllocationSample) are taken at a fixed rate and are therefore a statistical estimate, not an exhaustive log — they are cheap precisely because they do not record every occurrence. Threshold events (jdk.JavaMonitorEnter, and any custom event you write) are exact — every occurrence that clears the configured duration threshold is recorded, none that don’t are. Confusing the two is the root of two of the traps further down.
Going deeper: the chunk format and constant pools
A .jfr file is a sequence of self-contained chunks, each with its own header, event data, and constant pools (interned strings, stack traces, class names) so that a chunk can in principle be read on its own. This is also why jfr summary live-demo.jfr below reports “Chunks: 2” for a single recording that had one mid-flight dump taken — the dump closes the current chunk and starts a new one. The jfr tool’s own reference documents the chunk model in more depth than this post needs.
- Full event glossary and the fields each one carries: jdk.jfr.consumer API docs
- JEP that introduced JFR to OpenJDK: JEP 328: Flight Recorder
Recording six seconds of a real app
The companion app ships three endpoints built to misbehave on purpose — a naive recursive Fibonacci for CPU, an allocation-churning string/byte-list builder, and asynchronized block sixteen threads fight over — plus one custom business event. scripts/load.sh drives all four kinds of load; scripts/capture-jfr.sh wraps the whole sequence — start, load, mid-flight snapshot, stop — around a running PID.
$ jcmd 5287 JFR.start name=demo settings=profile maxsize=256m
5287:
Started recording 15.
$ curl -s localhost:8080/api/jfr/recordings
[{"id":15,"name":"demo","state":"RUNNING","startTime":"2026-10-01T04:30:41.255843977Z","maxSize":268435456,"maxAge":"null","destination":"null"}]
That first block is the full command — settings=profile picks one of the two bundled .jfc files (more on what the two actually differ on further down), and maxsize=256m caps the in-memory/disk footprint. Output quoted from docs/output/02-start-recording-and-diagnostics.txt; the curl line hits a diagnostic endpoint described later in this post.
After six seconds carrying real CPU, allocation, lock-contention and order-processing load, the recording’s own summary is the honest total:
Chunks: 2
Start: 2026-10-01 04:29:03 (UTC)
Duration: 6 s
Event Type Count Size (bytes)
=============================================================
jdk.ModuleExport 1756 20764
jdk.ActiveSetting 1137 30480
jdk.BooleanFlag 992 31418
...
jdk.ObjectAllocationSample 317 5081
jdk.ExecutionSample 98 1176
com.ankurm.jfr.OrderProcessed 23 809
jdk.JavaMonitorEnter 15 414
Full output in docs/output/10-final-summary.txt. The next four sections are exactly those four counts, traced back to the real stack frames and field values behind them.
The flags that start every bundled recording. “Chunks: 2” for a single recording that never stopped and restarted is correct, not a bug — a mid-flight JFR.dump closes the chunk it was writing and opens a new one, which is exactly what happened here (see the section on inspecting a live recording below). If your own count of chunks does not match an expected number of dumps plus one, that mismatch is worth investigating before anything else.
- Full recording lifecycle and chunk rotation:
jfrtool reference - The two bundled settings files, as shipped:
$JAVA_HOME/lib/jfr/default.jfcandprofile.jfc
Where the CPU time actually went: stack sampling finds the hot method
jdk.ExecutionSample is a periodic event: by default every 10 ms (profile settings sample a little faster), the JVM pauses one thread long enough to capture its stack and records only the top frames. Six concurrent calls to GET /api/cpu/fibonacci?n=38 — naive recursive Fibonacci, exponential in n, deliberately bad — against WorkloadService.fibonacci():
public long fibonacci(int n) {
if (n <= 1) {
return n;
}
return fibonacci(n - 1) + fibonacci(n - 2);
}
$ jfr print --events jdk.ExecutionSample --stack-depth 1 recordings/live-demo.jfr \
| grep -A1 stackTrace | grep -v 'stackTrace\|^--' | sed 's/^\s*//' | sort | uniq -c | sort -rn
62 com.ankurm.jfr.service.WorkloadService.fibonacci(int) line: 40
13 com.ankurm.jfr.service.WorkloadService.churnAllocations(int) line: 56
9 com.ankurm.jfr.service.WorkloadService.churnAllocations(int) line: 52
...
total jdk.ExecutionSample events in recording: 98
fibonacci() share of samples: 62 / 98 = 63.3%
Full stack-frame breakdown in docs/output/03-hot-method-samples.txt. Sixty-two of ninety-eight leaf samples, across the whole six-second window, landed in one recursive call — that is the signature of a genuine CPU hot spot rather than noise: a method that keeps showing up as the leaf frame, not just somewhere in the stack.
Going deeper: why the leaf frame, and the sampling bias that comes with it
Grouping by the leaf (innermost) frame rather than the full stack is deliberate here — it answers “where is the CPU actually spent” rather than “which call paths exist.” The trade-off is safepoint bias: HotSpot can only take a stack sample at a safepoint-capable point in generated code, which systematically under-samples tight loops with no safepoint poll inside them. Async-profiler’s AsyncGetCallTrace approach exists specifically to sidestep this; JFR’s sampler improved markedly from JDK 11 onward but the bias is not fully gone. For a method as CPU-bound and recursive as this one it does not change the conclusion, but it is the reason a flat 63% is a strong signal rather than a guarantee that nothing closer to 70% is being missed.
- How HotSpot samples stacks and the safepoint-bias caveat: Why JVM profilers are still safepoint biased
What’s being allocated, and from where
jdk.ObjectAllocationSample is the allocation equivalent — a sampled, not exhaustive, record of allocating call sites, throttled by the active settings (300/s under profile). Three concurrent calls to GET /api/alloc/churn?iterations=400000, backed by churnAllocations(), which builds a String by concatenation, converts it to a byte[], then boxes every byte into an ArrayList<Byte> — three short-lived allocations per loop turn, on purpose:
String s = "order-" + i + "-" + (i * 31) + "-padding-padding-padding";
byte[] bytes = s.getBytes();
List<Byte> boxed = new ArrayList<>(bytes.length);
for (byte b : bytes) {
boxed.add(b); // autoboxing on purpose
}
$ jfr print --events jdk.ObjectAllocationSample recordings/live-demo.jfr | grep objectClass \
| sed 's/^\s*//' | sort | uniq -c | sort -rn
154 objectClass = java.lang.Object[] (classLoader = bootstrap)
111 objectClass = byte[] (classLoader = bootstrap)
21 objectClass = java.util.ArrayList (classLoader = bootstrap)
19 objectClass = java.lang.String (classLoader = bootstrap)
...
Top allocating stack frames (--stack-depth 1), same recording:
153 java.util.ArrayList.<init>(int) line: 157
58 java.lang.String.encodeUTF8(byte, byte[], boolean) line: 1305
49 jdk.internal.misc.Unsafe.allocateUninitializedArray(Class, int) line: 1396
Full output in docs/output/04-allocation-samples.txt. The two biggest classes by count, Object[] and byte[], are not two separate problems — both trace back to the same new ArrayList<>(bytes.length) line: Object[] is the list’s own resized backing array as each boxed Byte is added, byte[] is s.getBytes(). That is the value of the stack-frame breakdown over the class breakdown: the class list says what is being created, the stack list says which line to fix.
- Why this allocation count is throttled, and what happens when a second recording’s lower threshold is also active: see the section on shared thresholds below
jdk.ObjectAllocationSamplefield reference: jdk.jfr.consumer docs
Watching sixteen threads queue for one lock
jdk.JavaMonitorEnter is a threshold event: it records how long a thread waited to enter a synchronized block, and by default only keeps waits above a configured floor. GET /api/lock/contend?workers=16&holdMillis=20 releases sixteen threads at once (via a CountDownLatch, in WorkloadService.contend()) to fight over one synchronized block that holds for 20 ms:
$ jfr print --events jdk.JavaMonitorEnter recordings/live-demo.jfr | grep duration | sort | uniq -c
1 duration = 101 ms
1 duration = 122 ms
1 duration = 142 ms
1 duration = 162 ms
1 duration = 182 ms
1 duration = 20.4 ms
1 duration = 203 ms
...
1 duration = 81.0 ms
Full fifteen-event list in docs/output/05-lock-contention-live-demo.txt. Fifteen events for sixteen threads — one enters immediately and is never a waiter — stepping up in roughly 20 ms increments: 20.4, 40.6, 60.9, 81.0, 101… up to 303 ms for the sixteenth.
jdk.JavaMonitorEntervsjdk.ThreadPark(for non-monitor blocking likeLock.lock()orCompletableFuture.get()): both exist, only the first was exercised here- Default threshold for this event, and why it is easy to miss waits like this one entirely: next section
Writing your own event: the whole API is begin, end, commit
JFR events are not only built-in.OrderProcessedEvent is a custom event for a fictional “order processed” business operation — the entire API surface is extending jdk.jfr.Event, annotating it, and adding fields:
@Name("com.ankurm.jfr.OrderProcessed")
@Label("Order Processed")
@Category({"ankurm.com demo", "Orders"})
@StackTrace(true)
@Threshold("20 ms")
public class OrderProcessedEvent extends Event {
@Label("Order ID") public String orderId;
@Label("Warehouse") public String warehouse;
@Label("Amount (cents)") public long amountCents;
@Label("Item Count") public int itemCount;
@Label("Slow Reason") public String slowReason;
}
OrderService.processOrder() uses it: begin(), do the work, end(), check shouldCommit(), set fields, commit() — all inside a try/finally, which matters a lot (see two sections down):
OrderProcessedEvent event = new OrderProcessedEvent();
event.begin();
try {
amountCents = priceItems(itemCount);
slowReason = maybeSimulateSlowPath();
} finally {
event.end();
if (event.shouldCommit()) {
event.orderId = orderId;
event.warehouse = WAREHOUSES[ThreadLocalRandom.current().nextInt(WAREHOUSES.length)];
event.itemCount = itemCount;
event.slowReason = slowReason;
event.commit();
}
}
A JUnit test proves the event works through the pure Java API, with no server and no jcmd at all — it starts a jdk.jfr.Recording in-process, processes 20 orders, stops, and reads the file back:
events recorded: 20
events with slowReason: 4
events without reason: 16
first event fields:
eventType = com.ankurm.jfr.OrderProcessed
orderId = TEST-0
warehouse = BLR-2
itemCount = 3
duration(ms) = 5
hasStackTrace = true
Test and output in OrderProcessedEventTest.java and docs/output/01-order-event-test.txt. Against the live app, 60 order-processing calls with roughly a third deliberately slowed past the 20 ms @Threshold:
$ jfr print --events com.ankurm.jfr.OrderProcessed recordings/live-demo.jfr | grep -c '^com.ankurm'
23
Twenty-three of sixty orders were kept, in docs/output/06-custom-event-live-demo.txt — every one of them carrying slowReason = "inventory-lock-wait" and a duration at or above 20 ms. None of the fast orders appear at all: the threshold discarded them before commit() ever ran.
Going deeper: why @Threshold on a custom event is a default, not a guarantee
@Threshold("20 ms") only takes effect when the active recording’s settings say nothing about this specific event type. Both bundled .jfc files are silent about com.ankurm.jfr.OrderProcessed — they only configure jdk.* events — so the annotation is what actually governs it under jcmd <pid> JFR.start settings=profile. If you want to override a custom event’s threshold at recording time the same way you can override a built-in one, you do it exactly the same way: a custom .jfc file, or -XX:FlightRecorderOptions, naming the event by its @Name.
- Full custom-event authoring guide: jdk.jfr.Event Javadoc
- What happens when the
try/finallyabove is left out: two sections down
The default settings will hide real problems from you
The two settings files bundled with every JDK,default.jfc and profile.jfc, disagree on thresholds for several events — jdk.JavaMonitorEnter is 20 ms under default, 10 ms under profile. Forty rounds of a 2-worker, 12 ms-hold contention call, run against each in isolation:
--- settings=default (jdk.JavaMonitorEnter threshold = 20 ms) ---
$ jfr print --events jdk.JavaMonitorEnter recordings/solo-default.jfr | grep -c duration
0
--- settings=profile (jdk.JavaMonitorEnter threshold = 10 ms) ---
$ jfr print --events jdk.JavaMonitorEnter recordings/solo-profile.jfr | grep -c duration
40
--- settings=default again, this time with a 35 ms hold (above BOTH thresholds) ---
$ jfr print --events jdk.JavaMonitorEnter recordings/solo-default-longhold.jfr | grep -c duration
10
Full transcript in docs/output/07-threshold-isolated-comparison.txt. Zero of forty 12 ms waits caught under default; all forty caught under profile; the same default recording catches every wait once it is raised to 35 ms. A lock contention problem with waits in the 10–20 ms range is completely invisible to a recording started with plain jcmd <pid> JFR.start — which defaults to default.jfc.
“I ran a recording and saw nothing” is not proof nothing happened. It is proof nothing cleared that recording’s threshold for that event type. Before concluding a suspected lock, allocation, or I/O problem does not exist, rerun withsettings=profileor a custom.jfcwith the relevant threshold set near zero, specifically for the event type you suspect.
- Full threshold table for both bundled files: unzip
$JAVA_HOME/lib/jfr/default.jfcandprofile.jfc— they are plain XML - What happens to this exact picture the moment a second recording is also active: next section
A second recording on the box can silently widen what yours captures
This is the one most people never discover until it costs them an afternoon. The identical 40-round, 12 ms-wait workload, but now two recordings are started at once — onesettings=default, one settings=profile:
$ jfr summary recordings/compare-default.jfr | grep JavaMonitorEnter
jdk.JavaMonitorEnter 40 1080
$ jfr summary recordings/compare-profile.jfr | grep JavaMonitorEnter
jdk.JavaMonitorEnter 40 1080
Full comparison in docs/output/08-concurrent-recordings-shared-threshold.txt. Both recordings show all forty events — including the one configured with a 20 ms threshold, for waits that are only 12 ms long. Run alone (previous section), that same default configuration caught zero.
jdk.JavaMonitorEnter are a single instrumentation check shared by the JVM across every currently active recording, not a private filter per recording — the effective threshold in force is the minimum requested by any active recording. A colleague’s ad hoc jcmd JFR.start, or an APM agent’s own continuous background recording, with a lower threshold for an event type you care about will silently widen what your recording captures for that same type.
“My recording uses the default profile” does not tell you what your recording contains. On a box where anything else might also be recording — and on a managed platform, something usually is — check jcmd <pid> JFR.check for other active recordings before reasoning about what a threshold should have excluded.
jcmd <pid> JFR.checkto list every recording currently active on a JVM, not only your own- Same behaviour, differently surprising, for sampled (not threshold) events like allocation: the throttle is also effectively shared
Losing events silently: the missing try/finally
BrokenEventPattern exists purely to show the one way to lose your own events with zero warning — it is not wired into the running app, but it compiles and runs:
public static void processWithoutTryFinally(String orderId) {
OrderProcessedEvent event = new OrderProcessedEvent();
event.begin();
riskyStep(orderId); // if this throws, the lines below never run
event.end();
if (event.shouldCommit()) {
event.orderId = orderId;
event.commit();
}
}
Compare this to OrderService.processOrder() two sections up, which wraps the identical sequence in try/finally. Driven 200 times, with roughly one call in five throwing by design:
$ java -cp target/classes com.ankurm.jfr.events.BrokenEventPatternDemo
calls: 200
exceptions thrown: 41
events committed: 159
expected if lossless: 200
events missing: 41 (== exceptions thrown)
Full output in docs/output/11-broken-event-pattern.txt. Forty-one missing events, exactly matching forty-one thrown exceptions. The event’s threshold was forced to 0 ms for this run specifically to rule out “too fast to clear the threshold” as an alternative explanation — every missing event is attributable to the missing try/finally, nothing else.
No exception, log line, orJFR.checkoutput calls this out. A dropped custom event on the unhappy path is invisible by default — the only way to notice is to count expected events against committed ones, the way the demo above does. If an event is meant to fire on every call including the failing ones, thebegin()/commit()pair belongs insidetry/finally, the same way resource cleanup does.
- The correct pattern, in a real service method: OrderService.java
The dump/stop bug that quietly doubles every event
This one was found while building this exact post, not invented for it.scripts/reproduce-dump-bug.sh reproduces it on demand:
$ jcmd 5287 JFR.start name=live settings=profile filename=recordings/profile-run.jfr maxsize=256m
$ # ... real load ...
$ jcmd 5287 JFR.dump name=live filename=recordings/profile-run.jfr # same path as JFR.start's filename=
$ jcmd 5287 JFR.stop name=live # no filename -> falls back to that SAME path
$ jfr summary recordings/profile-run.jfr | grep -i 'Chunks\|JavaMonitorEnter\|OrderProcessed'
Chunks: 3
jdk.JavaMonitorEnter 30 768
com.ankurm.jfr.OrderProcessed 56 1988
Thirty JavaMonitorEnter events for a workload independently confirmed (earlier section) to produce fifteen; fifty-six OrderProcessed events for sixty calls that should keep around a third. Both are almost exactly double a plausible real count. Checking for exact duplicates confirms it:
$ jfr print --events com.ankurm.jfr.OrderProcessed --json recordings/profile-run.jfr \
| python3 -c "import json,sys; d=json.load(sys.stdin); e=d['recording']['events']; \
print('printed:', len(e)); \
print('unique (orderId,startTime):', len({(x['values']['orderId'], x['values']['startTime']) for x in e}))"
printed: 56
unique (orderId,startTime): 28
Full transcript, including confirmation that jdk.JavaMonitorEnter shows the same 2x pattern (30 printed, 15 real), in docs/output/09-dump-duplication-bug.txt; the buggy recording itself is committed, unedited, as recordings/dump-duplication-bug.jfr if you want to see the doubled events in JMC yourself.
JFR.dump was pointed at the exact same file path the recording was already configured to write to via filename= on JFR.start. The following JFR.stop, given no filename of its own, falls back to that same configured destination and writes the complete recording there again, on top of what the mid-flight dump had already written.
The fix used for every other recording in this repository. Either never setfilename=onJFR.startat all — only ever name a file explicitly onJFR.dumporJFR.stop, each a distinct path — or if a recording does have a configured destination, neverJFR.dumpto that exact same path mid-flight. scripts/capture-jfr.sh is the clean version: nofilename=on start, a distinct path on the mid-flight dump, a distinct path on stop.
- If you suspect a recording you already have is affected: check for exact duplicate (eventType, startTime) pairs the way the Python one-liner above does, per event type
Inspecting a running recording without stopping it
JFR.dump does not have to mean “end of recording” — dumped to a fresh path, it is a safe, repeatable snapshot of everything captured so far, and the recording keeps running afterward. The flagship recording for this post was produced exactly this way, with one mid-flight dump to a separate file:
$ jcmd 5287 JFR.start name=live settings=profile maxsize=256m
$ # ... cpu, allocation, lock-contention load ...
$ jcmd 5287 JFR.dump name=live filename=recordings/mid-flight-snapshot.jfr
$ # ... order-processing load ...
$ jcmd 5287 JFR.stop name=live filename=recordings/live-demo.jfr
Both files are committed — mid-flight-snapshot.jfr has the CPU, allocation and lock events but none of the order-processing ones that came after it was taken; live-demo.jfr has everything. Neither overlaps the other, which is the whole point of giving each a distinct path, per the previous section.
The companion app also carries a small diagnostic endpoint that asks the running JVM about its own recordings directly, through the pure Java API rather than shelling out to jcmd:
@GetMapping("/api/jfr/recordings")
public String recordings() {
List<Recording> recordings = FlightRecorder.getFlightRecorder().getRecordings();
return recordings.stream()
.map(r -> "{\"id\":" + r.getId()
+ ",\"name\":\"" + r.getName() + "\""
+ ",\"state\":\"" + r.getState() + "\"" + /* ... */ "}")
.collect(Collectors.joining(",", "[", "]"));
}
Full controller in DiagnosticsController.java; its output while a recording is active is the curl line in docs/output/02-start-recording-and-diagnostics.txt near the top of this post.
Delete this endpoint, or gate it, before shipping. It has no business being reachable from the internet on a real service — it exists here purely so the post and the README could show real, live Flight Recorder state instead of a description of one. The same goes for /api/jfr/event-types next to it.
- Full diagnostic endpoint source: DiagnosticsController.java
- Pure Java recording API, no
jcmdor external process needed at all: jdk.jfr.Recording Javadoc
Should you run Flight Recorder in production?
Yes, by default, with the caveats this post just walked through. JFR’s design goal from JEP 328 onward was overhead low enough to run continuously in production — typically reported in the low single-digit percent fordefault.jfc, higher for profile.jfc‘s denser sampling — and that is the entire reason it ships enabled-by-default rather than as an opt-in diagnostic you bolt on afterward.
What this post should leave you with is not “turn it on,” which is one command, but the four traps that turn a recording from evidence into noise: trusting a default threshold to catch something it is configured to ignore, trusting a recording’s isolation from every other recording that might be active on the same JVM, losing custom events on the unhappy path for want of a try/finally, and corrupting a recording by dumping and stopping to the same path. None of the four produce an error message. All four are things a reader of this post can now check for by name.
What to actually do on Monday. Leave JFR’s default continuous recording running. When you need to look closely at something specific, start a second, targeted recording withsettings=profileor a custom.jfcnaming the exact events and thresholds you care about, dump it to its own path, and remember that its thresholds are a floor shared with whatever else is already recording — check withJFR.checkfirst. Delete any diagnostic endpoint like the one above before the build that ships.
Reproducing this
Every number in this post traces to a file underdocs/output/ or a .jfr file under recordings/, both committed, unedited.
git clone https://ankurm.com/git.app/asmhatre/jfr.git
cd jfr
mvn -q -B -DskipTests package
scripts/run.sh -d
scripts/capture-jfr.sh $(pgrep -f jfr-demo.jar)
# or, to regenerate every docs/output/ file including the JUnit-driven ones:
scripts/run-all.sh
Further reading
- asmhatre/jfr — the complete companion repository: the Spring Boot app, every script, eleven captured-output transcripts, and seven real
.jfrrecordings - JEP 328: Flight Recorder — OpenJDK
- The
jfrcommand-line tool reference — Oracle, JDK 25 - jdk.jfr.Event Javadoc — custom event authoring
- JDK Mission Control — the GUI these same recordings open in
- Diagnosing Virtual Thread Pinning in Production: JFR Events, jcmd, and Real Fixes — a second custom-event, jcmd-driven diagnosis, this time for carrier-thread pinning
- Deploying Spring Boot 4 on Kubernetes — what to do once you know which endpoint is slow and why
No Comments yet!