Lab DP2: JFR and async-profiler

Background

Lab DP1 used hot_threads — a sampling profiler built into the cluster. It is perfect for "which thread, which class," but it samples coarsely and only shows Java frames. When you need a precise, whole-process picture — every hot method weighted by how much CPU it really burns, or every allocation site weighted by how many bytes it churns — you reach for a real profiler. This lab drives the two that matter for OpenSearch:

• Java Flight Recorder (JFR) — the always-on, low-overhead recorder built into the JVM. You start a recording, run load, dump it, and open the .jfr file.
• async-profiler — a sampling profiler that produces flame graphs for CPU, allocations, and lock contention, with accurate native frames (it samples on perf_events / AsyncGetCallTrace, so it sees through JIT and into native).

You will attach both to a live ./gradlew run node under load, produce a CPU flame graph and an allocation flame graph, read them to find a hot path, and tie an allocation hotspot back to OpenSearch's BigArrays / object churn.

Why This Matters for Contributors

hot_threads tells you a terms agg is hot. A flame graph tells you which 12% of that agg's CPU is OrdinalMap lookups, which 30% is in BigArrays.grow, and which 8% is GC pressure from a per-doc allocation you can hoist out of the loop. That resolution is what turns "this is slow" into a concrete, reviewable optimization PR — the kind maintainers merge. Allocation profiling in particular is how you find the per-document garbage that drives GC pauses, which hot_threads cannot see at all. Every serious OpenSearch performance PR is backed by a before/after flame graph.

Prerequisites

• An OpenSearch checkout you can ./gradlew run, and the shop index + /tmp/load.sh load generator from Lab DP1 (re-create them if needed).
• A JDK with jcmd (ships with the JDK). JFR is included in OpenJDK 11+.
• async-profiler: download a release for your OS/arch from https://github.com/async-profiler/async-profiler/releases. The binary is asprof (older releases: profiler.sh). On Linux you may need to relax perf_event_paranoid (see Troubleshooting).
• Read the intensive "JVM tooling table" section.

Note: macOS works for CPU profiling with async-profiler but cannot use perf_events; allocation/lock profiling and itimer-based CPU work fine. Linux gives the fullest picture. JFR is identical on both.

Step-by-Step Tasks

Step 1 — Start a node and find its PID

# In your OpenSearch checkout, start a single node (serves on :9200):
./gradlew run    # leave this running in one terminal

# In another terminal, find the node JVM PID:
PID=$(jps -l | grep -iE 'opensearch|Bootstrap|Gradle' | grep -iv gradle | awk '{print $1}')
echo "node PID = $PID"
# Sanity-check it's the node, not the gradle daemon:
jcmd "$PID" VM.command_line | head

If jps is ambiguous, the node process is the one whose command line contains org.opensearch.bootstrap — confirm with jcmd "$PID" VM.command_line.

Step 2 — Put the node under load

Reuse the expensive-agg load from Lab DP1 so the profiler has something hot to sample:

for i in 1 2 3 4 5 6; do /tmp/load.sh & done
LOAD_PIDS=$(jobs -p)
echo "load running (pids: $LOAD_PIDS) -- profile now, then: kill $LOAD_PIDS"

Step 3 — Record with JFR

JFR has two start modes. Mode A starts a recording on an already running JVM via jcmd (what you'll usually do in the field). Mode B starts it at JVM launch with a flag (for capturing startup).

# --- Mode A: attach to the running node and record 30s, then dump ---
jcmd "$PID" JFR.start name=os duration=30s filename=/tmp/os.jfr settings=profile
# (settings=profile = higher-detail than the default 'default' profile)

# Watch / dump on demand:
jcmd "$PID" JFR.check                       # list active recordings
jcmd "$PID" JFR.dump name=os filename=/tmp/os-now.jfr   # dump without stopping
jcmd "$PID" JFR.stop  name=os filename=/tmp/os.jfr      # stop + write

# --- Mode B: start at launch (edit the run JVM args / jvm.options) ---
# -XX:StartFlightRecording=duration=60s,filename=/tmp/start.jfr,settings=profile
# Useful when the problem happens during startup/recovery, before you can jcmd.

Now read the recording. The cross-platform reader is jfr (ships with the JDK); JDK Mission Control (JMC) is the GUI:

# Top hot methods straight from the CLI -- no GUI needed:
jfr print --events jdk.ExecutionSample --stack-depth 8 /tmp/os.jfr | head -60

# A quick "what allocated the most" view:
jfr print --events jdk.ObjectAllocationSample /tmp/os.jfr | head -40

# Summary of everything in the file:
jfr summary /tmp/os.jfr | head -40

The jdk.ExecutionSample events are JFR's CPU samples; the repeated top frame across them is your hot method — the same answer hot_threads gave, but weighted precisely and with allocation/lock/GC events alongside. Open /tmp/os.jfr in JMC for the flame-graph and "Method Profiling" / "Memory" pages if you want the GUI.

Step 4 — CPU flame graph with async-profiler

async-profiler attaches to the live PID and writes an interactive HTML flame graph. The -e cpu event samples on-CPU stacks:

ASPROF=/path/to/async-profiler/bin/asprof      # or .../profiler.sh on older releases

# 30 seconds of CPU sampling -> an interactive flame graph:
"$ASPROF" -e cpu -d 30 -f /tmp/cpu-flame.html "$PID"
echo "open /tmp/cpu-flame.html in a browser"

# Equivalent older syntax:
# /path/to/profiler.sh -e cpu -d 30 -f /tmp/cpu-flame.html "$PID"

How to read a CPU flame graph:

• Width = time. A box's width is the fraction of samples that had that frame on the stack. Wider = more CPU. Height is just call depth — tall is not bad, wide is.
• Read top-down for hotspots. The widest boxes near the top (the leaves) are where the CPU actually is — the method doing the work, not its callers.
• Find your plateau. Look for a wide leaf plateau. For the Lab DP1 load expect a wide region under ...GlobalOrdinalsStringTermsAggregator...collect → OrdinalMap.getGlobalOrds / LongValues.get — the per-doc ordinal lookups.

flowchart TD
    Root["all samples (100% width)"] --> QP["QueryPhase.execute (wide)"]
    QP --> BS["BulkScorer.score"]
    BS --> LBC["LeafBucketCollector.collect"]
    LBC --> Agg["GlobalOrdinals...collect (WIDE leaf = the hotspot)"]
    LBC --> Ord["OrdinalMap.getGlobalOrds (WIDE leaf)"]
    QP --> Score["Similarity score (narrow)"]

Note: Click a box in the HTML to zoom into that subtree, and use the search box (top-right) to highlight every frame matching a regex (e.g. BigArrays) — the total highlighted width is that pattern's share of CPU. This is how you answer "how much of my time is really in X?"

Step 5 — Allocation flame graph and the BigArrays connection

CPU profiling cannot see GC pressure from short-lived garbage. Allocation profiling (-e alloc) samples allocation sites weighted by bytes — the leaves are where your heap garbage is born:

# Sample allocations for 30s -> a flame graph weighted by allocated bytes:
"$ASPROF" -e alloc -d 30 -f /tmp/alloc-flame.html "$PID"
echo "open /tmp/alloc-flame.html -- the widest leaves are your biggest allocators"

In the allocation flame graph, search for BigArrays. OpenSearch's aggregations and many internal buffers allocate through org.opensearch.common.util.BigArrays — paged, breaker-accounted arrays (LongArray, DoubleArray, ObjectArray) used for per-bucket state. A wide BigArrays.grow / BigArrays.newLongArray plateau under the agg's collect means the aggregation is resizing/allocating its bucket arrays heavily — which both burns CPU (the copy on grow) and feeds GC.

# See what BigArrays does and how aggregations use it, in your checkout:
find server -name BigArrays.java
grep -n "newLongArray\|grow\|resize\|class BigArrays\|adjustBreaker\|PageCacheRecycler" \
  server/src/main/java/org/opensearch/common/util/BigArrays.java | head
grep -rn "bigArrays\.\(newLong\|newDouble\|newObject\|grow\)" \
  server/src/main/java/org/opensearch/search/aggregations/ | head

This is the contributor payoff: a flame graph that shows a per-document allocation in a hot loop is a concrete optimization (hoist it out, reuse a buffer, pre-size the BigArrays), and you can prove the win with a before/after -e alloc graph.

Step 6 — Lock-contention flame graph (when the symptom is "block")

If Lab DP1's hot_threads?type=block showed contention rather than CPU, profile the locks:

# Sample lock/monitor contention -> flame graph weighted by blocked time:
"$ASPROF" -e lock -d 30 -f /tmp/lock-flame.html "$PID"

The leaves here are the monitors threads waited on. A wide leaf is a contended lock — the same thing a thread dump's BLOCKED ... waiting to lock <0x...> shows, but aggregated and ranked. (For the pure-CPU agg load this graph will be nearly empty — which, as in Lab DP1, confirms the bottleneck is compute, not a lock.)

Step 7 — Stop everything cleanly

kill $LOAD_PIDS 2>/dev/null                  # stop the load generator
jcmd "$PID" JFR.stop name=os 2>/dev/null     # stop JFR if still running
# async-profiler stops on its own after -d 30; to stop a manual run:
# "$ASPROF" stop -f /tmp/out.html "$PID"

Deliverables

• /tmp/os.jfr plus the jfr print --events jdk.ExecutionSample output showing the top hot method.
• /tmp/cpu-flame.html — a CPU flame graph with the agg collect / OrdinalMap plateau identified as the hotspot (note its approximate width %).
• /tmp/alloc-flame.html — an allocation flame graph with a BigArrays allocation site called out, and a one-line explanation tying it to the agg's bucket arrays.
• A sentence stating, from the flame graphs, where you would optimize and why.

Expected Output

# jfr print (Step 3)
jdk.ExecutionSample {
  stackTrace = [
    org.apache.lucene.util.packed.... 
    org.opensearch.search.aggregations.bucket.terms.GlobalOrdinalsStringTermsAggregator...collect()
    org.opensearch.search.aggregations.LeafBucketCollector.collect()
    ...
  ]
}    # this stack repeats across most ExecutionSamples -> the hotspot

# CPU flame graph (Step 4): a wide plateau ~85% under
#   QueryPhase.execute -> ... -> GlobalOrdinals...collect / OrdinalMap.getGlobalOrds

# alloc flame graph (Step 5): a wide region under
#   ...collect -> BigArrays.grow / newLongArray   (bucket arrays churning)

Troubleshooting

Stretch Goals

• Before/after a fix. Take a baseline -e alloc graph, then reduce the agg size (or add a keyword-with-doc-values path) and take another. Quantify the drop in BigArrays allocation width.
• Differential flame graph. Use async-profiler's --total / two-recording diff (or JMC) to show only what changed between two runs.
• Profile indexing instead of search. Drive the bulk loader from Lab DP1 and CPU-profile the [write] threads; find the IndexWriter/analysis hotspots.
• JFR continuous mode. Configure a default JFR recording in jvm.options (-XX:StartFlightRecording=disk=true,maxsize=256m) so a recording is always available when something goes wrong in production — then JFR.dump on incident.
• GC + alloc together. Open the .jfr in JMC, correlate the allocation rate with the GC pause page, and decide whether the fix is "allocate less" or "size the heap differently" — cross-link Lab DP3.

Coding Exercises

A flame graph is a screenshot; a script that turns a .jfr/collapsed-stack file into a ranked, diffable number is a tool. These exercises make you write that tooling and back an allocation claim with a test. Locate every class with rg/find.

1. (warm-up) A JFR hotspot ranker. Write jfr_top.py that shells out to jfr print --events jdk.ExecutionSample --stack-depth 1 /tmp/os.jfr, tallies the leaf (top) frame across all samples, and prints the top-10 hot methods with their percent share. Verify the GlobalOrdinalsStringTermsAggregator...collect frame tops the list for the Lab DP1 load. This is the no-GUI equivalent of reading a flame graph's widest leaf.

2. (core) A collapsed-stack flame summarizer. Run async-profiler with -o collapsed -f /tmp/cpu.collapsed (folded-stack format: frame;frame;... count per line) instead of HTML. Write flame_share.py <pattern> that sums the sample count of every stack containing a regex (e.g. BigArrays, OrdinalMap) and prints it as a percent of total — answering "how much of CPU is really in X?" programmatically. This is the search-box width number, computed.

3. (core) A before/after allocation diff. Capture two collapsed -e alloc profiles — one with the 10k-bucket agg, one with size:10 — and write alloc_diff.py a.collapsed b.collapsed that prints the per-leaf byte-weight delta, sorted by largest drop. Confirm the BigArrays.grow/newLongArray leaf shrinks. You've just built the artifact every perf PR needs: a quantified before/after.

4. (advanced) An allocation regression test for an agg. The contributor payoff is proving an allocation claim in a test, not a flame graph. Find how OpenSearch accounts allocations through breakers/BigArrays:

   rg -n "class BigArrays|newLongArray|adjustBreaker|ramBytesUsed|CircuitBreaker" \
     server/src/main/java/org/opensearch/common/util/BigArrays.java
   rg -ln "MockBigArrays|new MockBigArrays" server/src/test test/framework
   

   Write an AggregatorTestCase test for the terms agg that uses MockBigArrays (which tracks every byte and asserts no leaks on close) and asserts the number of distinct BigArrays allocations stays within a bound for a fixed dataset. Then shrink the agg size and assert the bound drops. MockBigArrays' leak detection is itself the leak-detector — failing the test if any array isn't released.

5. (Advanced challenge) A JFR-driven micro-benchmark harness. Build a small standalone Java program (or a JMH benchmark under benchmarks/ — rg -l "@Benchmark" benchmarks) that drives the hot path directly: construct an in-memory Lucene index, run the global-ordinals terms aggregation over it in a loop, and gate the JVM with -XX:StartFlightRecording=duration=30s,filename=bench.jfr,settings=profile. Then have your jfr_top.py (exercise 1) parse bench.jfr and fail (exit nonzero) if the agg collect frame's share exceeds a threshold — a profiling-based regression gate, the seed of an automated perf check. Bonus: emit the result as JSON and have the harness compare two builds (a good/bad pair, foreshadowing Lab DP4's performance bisect). Find the existing benchmark/test plumbing with rg -ln "OpenSearchTestCase|RandomIndexWriter" server/src/test to crib the index-building boilerplate.

Issues to Practice On

Performance issues live or die on the flame graph attached to them — bring one.

List labels first (gh label list --repo opensearch-project/OpenSearch) — the area taxonomy drifts.

Representative patterns. (a) "This operation allocates too much / GC pauses under load X" — reproduce on ./gradlew run, take an -e alloc flame graph, name the allocation site (often a per-doc allocation in a hot loop, or an under-sized BigArrays resizing), propose hoisting/pre-sizing it, and prove the win with a before/after -e alloc graph plus a MockBigArrays test. (b) "Hot method Y dominates CPU" — capture JFR + a CPU flame graph, locate the method via rg, and either reduce its work or its call count; back it with a benchmarks/ JMH result.

Planted-bug drill. Introduce an allocation regression: in a hot collect/grow path (find one with rg -n "bigArrays\.(newLong|newDouble|grow)" server/src/main/java/org/opensearch/search/aggregations), remove a pre-size hint or move an allocation inside a per-doc loop. Run your allocation test from exercise 4 (or the relevant *Tests found with rg -l "MockBigArrays" server/src/test) and watch the allocation count/leak assertion go red. Revert, then add a tighter assertion that pins the expected allocation count — the assertion that would have caught the regression.

Etiquette: claim before working, reproduce first, and every PR needs a test + a CHANGELOG.md entry + DCO Signed-off-by (git commit -s). See community-interaction.

Validation / Self-check

• You can start a JFR recording on a running node (both jcmd JFR.start and the -XX:StartFlightRecording flag) and read the top hotspot via jfr print.
• You can produce a CPU flame graph with async-profiler and explain why width, not height, marks the hotspot.
• You can produce an allocation flame graph, find a BigArrays allocation site, and explain why it both burns CPU and pressures GC.
• You can pick the right event (-e cpu vs -e alloc vs -e lock) for a given symptom, and know what an empty lock graph confirms.
• You can state, from a flame graph, a concrete optimization and how you'd prove it with a before/after recording.

Next: Lab DP3 — Heap and Thread Dumps, for when the problem is not CPU but a deadlock or retained memory.