Debugging and Profiling — Intensive

Every other masterclass teaches you how a subsystem is supposed to work. This one teaches you what to do when it doesn't — when a node is pinned at 100% CPU, when a query that should take 5ms takes 5s, when the heap fills and the JVM OutOfMemoryErrors, or when an aggregation returns the wrong number. The skill that separates a senior OpenSearch contributor from a beginner is not knowing the code; it is knowing, under pressure, which tool answers which question — and being able to drive that tool to a root cause instead of guessing.

This chapter is organized around four questions a contributor actually asks:

  1. Why is it slow / hot? — _nodes/hot_threads, the Profile API, slow logs.
  2. Why is it stuck? — thread dumps, _tasks + cancellation, blocked pools.
  3. Why is it OOM? — heap dumps → Eclipse MAT, circuit breakers, _nodes/stats.
  4. Why is it wrong? — TRACE logging, a deterministic reproducer, git bisect.

It extends, and assumes you have read, three deep-dives: threadpools-concurrency (the pools a hot thread runs on, the cardinal "never block coordination threads" rule), circuit-breakers-memory (the breakers that trip before OOM), and search-execution (the query/fetch phases the Profile API breaks down). It also introduces the in-tree telemetry framework (org.opensearch.telemetry) and shows you how to add a span or a metric to a code path you are debugging.

Note: Throughout, the term cluster manager (formerly master) refers to the elected node that maintains and publishes cluster state. Several "stuck" symptoms below cascade from a thread that blocks the cluster-manager update or applier thread; that cascade is drawn in threadpools-concurrency.

The labs that go with this chapter:


The triage decision tree

Before any specific tool, internalize the order of operations. The mistake beginners make is reaching for a heap dump (slow, heavy, hard to read) when hot_threads (one HTTP call, instant) would have answered the question. Start at the top and only descend when the cheaper tool is inconclusive.

flowchart TD
    Start{"What is the symptom?"} --> Slow["slow / high CPU"]
    Start --> Stuck["hung / not progressing"]
    Start --> OOM["heap pressure / OOM"]
    Start --> Wrong["wrong result"]

    Slow --> HT["GET _nodes/hot_threads<br/>(who is burning CPU?)"]
    HT --> Prof["one slow query?<br/>_search {profile:true}"]
    HT --> JFR["whole-node CPU?<br/>JFR / async-profiler flame graph"]
    Prof --> SlowLog["recurring?<br/>enable search/index slow logs"]

    Stuck --> Tasks["GET _tasks?detailed<br/>(what is running, for how long?)"]
    Tasks --> Cancel["runaway task?<br/>POST _tasks/<id>/_cancel"]
    Tasks --> Dump["no progress at all?<br/>jstack / jcmd Thread.print"]
    Dump --> Pool["BLOCKED on a fixed pool<br/>or a coordination thread?"]

    OOM --> Stats["GET _nodes/stats (heap, breakers, fielddata)"]
    Stats --> Breaker["breaker tripping?<br/>which one, what limit?"]
    Stats --> Heap["leak / retention?<br/>jmap heap dump -> Eclipse MAT"]
    Heap --> GC["GC thrash?<br/>read -Xlog:gc* logs"]

    Wrong --> Trace["TRACE logging on the suspect logger"]
    Trace --> Repro["deterministic reproducer<br/>(-Dtests.seed, curl script)"]
    Repro --> Bisect["regression?<br/>git bisect 2.x..main"]
    Repro --> Debug["step through:<br/>./gradlew run --debug-jvm (attach 5005)"]

Memorize the first box under each symptom: hot_threads for slow, _tasks for stuck, _nodes/stats for OOM, TRACE logging for wrong. Those four calls cost you seconds and route you to the right heavyweight tool.


Why is it slow / hot?

_nodes/hot_threads — the first call, always

GET /_nodes/hot_threads is implemented by org.opensearch.action.admin.cluster.node.hotthreads.HotThreads. It is a sampling thread profiler built into the cluster: it snapshots every live thread's stack, sleeps a short interval (default 500ms), snapshots again, and reports the threads whose CPU/wait/block time grew the most — with their stacks. It needs no agent, no restart, no port; it is one HTTP call against a running node.

# The default: the 3 hottest threads per node, by CPU, 10 samples.
curl -s 'localhost:9200/_nodes/hot_threads'

# Tune it: more threads, longer window, and choose what "hot" means.
curl -s 'localhost:9200/_nodes/hot_threads?threads=5&interval=1s&type=cpu'
curl -s 'localhost:9200/_nodes/hot_threads?type=wait'    # who is parked/waiting
curl -s 'localhost:9200/_nodes/hot_threads?type=block'   # who is blocked on a monitor
type=What it ranks byUse when
cpu (default)CPU time consumed between samplesnode is CPU-bound, fans spinning
waittime spent in WAITING/TIMED_WAITINGthreads parked — pool starvation, lock waits
blocktime BLOCKED on a monitorlock contention — two threads fighting for a synchronized
# Find the implementation and the percentage/idle-filtering logic in a checkout:
find server -name HotThreads.java
grep -n "type\|interval\|isIdleThread\|percent\|busiest\|innerDetect" \
  server/src/main/java/org/opensearch/action/admin/cluster/node/hotthreads/HotThreads.java | head

The output is a percentage and a stack:

::: {node-0}{...}
   Hot threads at 2026-06-16T...,  interval=500ms, busiestThreads=3, type=cpu:

   98.4% (492ms out of 500ms) cpu usage by thread 'opensearch[node-0][search][T#7]'
     10/10 snapshots sharing following 23 elements
       app//org.apache.lucene.search.DisjunctionScorer.score(...)
       app//org.opensearch.search.aggregations.bucket.terms.GlobalOrdinalsStringTermsAggregator...collect(...)
       app//org.opensearch.search.query.QueryPhase.execute(...)
       ...

Read it like this:

  • The thread name tells you the pool. [search] → the SEARCH pool, so this is query/fetch work. [write], [refresh], [clusterApplierService], [generic] — each maps to a pool from threadpools-concurrency. A hot [clusterApplierService] thread is an emergency: state application is stalling.
  • N/10 snapshots sharing is the consensus. 10/10 sharing means the thread sat in that exact stack the whole window — a tight loop or genuinely expensive call. 3/10 means it churned through many stacks; look higher up the frames for the common ancestor.
  • The stack is your map into the code. The frame GlobalOrdinalsStringTermsAggregator says "a terms aggregation on a high-cardinality field"; you now grep that class and reason about cardinality.

Note: hot_threads is the single highest-leverage diagnostic in OpenSearch. It is safe to run in production, costs almost nothing, and answers "what is this node doing right now?" before you reach for anything heavier. Lab DP1 makes you read real stacks under load.

The Profile API — one query, broken down

hot_threads tells you which kind of work is hot. When the answer is "one specific slow query," the Profile API tells you where inside that query the time goes. Add "profile": true to any _search body:

curl -s 'localhost:9200/orders/_search' -H 'Content-Type: application/json' -d'
{
  "profile": true,
  "query": { "bool": { "must": [ {"match": {"body": "lucene"}} ],
                        "filter": [ {"range": {"price": {"gte": 10}}} ] } },
  "aggs": { "by_cat": { "terms": { "field": "category", "size": 20 } } }
}' | python3 -m json.tool

The response carries a profile block with per-shard, per-query timings. The key breakdown fields, in nanoseconds:

Breakdown fieldWhat it measuresA spike here means
create_weightbuilding the Weight (one-time per query)expensive query construction (huge terms, many clauses)
build_scorerconstructing the Scorer per segmentiterator/postings setup — many segments, costly filters
next_docadvancing to the next matching docthe matching scan itself — selectivity, postings size
advanceScorer.advance(target) (used by conjunctions)leapfrogging cost in bool/filter intersections
scorecomputing the BM25/similarity score per docscoring a huge result set; consider filter not must
matchtwo-phase TwoPhaseIterator.matches()expensive confirmation (phrase, geo) per candidate

The aggregation profile is separate, under aggregations, with its own breakdown: initialize, collect (the hot one — per-doc bucketing), build_aggregation, reduce. A terms agg dominated by collect is doing a lot of per-document ordinal lookups; cross-reference aggregations for the GlobalOrdinalsStringTermsAggregator internals.

flowchart TD
    Resp["_search profile response"] --> Shards["profile.shards[]"]
    Shards --> Q["searches[].query[]<br/>(the query tree)"]
    Shards --> C["searches[].collector[]<br/>(collector wall-time)"]
    Shards --> A["aggregations[]<br/>(per-agg breakdown)"]
    Q --> BD["breakdown:<br/>create_weight / build_scorer /<br/>next_doc / advance / score / match"]
    A --> ABD["breakdown:<br/>initialize / collect /<br/>build_aggregation / reduce"]

Two cautions that trip everyone up the first time:

Warning: Profiling has overhead — every next_doc/advance call is wrapped and timed. Absolute numbers are inflated; use the Profile API to find the relative hotspot (which clause, which collector), not to quote a real latency. And time_in_nanos is per shard; the coordinator-side merge/reduce is not in the per-shard tree (the agg reduce you see is the shard-local partial reduce).

Lab DP1 decodes a real timing tree end-to-end.

Slow logs — catch the slow ones you didn't run by hand

The Profile API needs you to run the slow query. Slow logs catch the slow queries that already happened, in production, per shard, automatically. They are configured by dynamic index settings with per-level thresholds:

curl -s -XPUT 'localhost:9200/orders/_settings' -H 'Content-Type: application/json' -d'
{
  "index.search.slowlog.threshold.query.warn":  "2s",
  "index.search.slowlog.threshold.query.info":  "1s",
  "index.search.slowlog.threshold.fetch.warn":  "500ms",
  "index.indexing.slowlog.threshold.index.warn":"1s",
  "index.indexing.slowlog.source": "1000"
}'
Setting prefixLogs whenWritten to
index.search.slowlog.threshold.query.*the query phase on a shard exceeds the threshold*_index_search_slowlog.json
index.search.slowlog.threshold.fetch.*the fetch phase (stored-field load) exceeds itsame
index.indexing.slowlog.threshold.index.*indexing a doc on a shard exceeds itindexing slowlog

Each threshold has warn/info/debug/trace levels so you can keep a noisy info channel and a quiet warn channel. The log line names the shard, the took time, and (truncated to index.indexing.slowlog.source) the source — so you can reproduce it.

# Tail them (path is logs/<cluster>_index_search_slowlog.json under your data/logs dir):
tail -f $OPENSEARCH_HOME/logs/*_index_search_slowlog.json | python3 -m json.tool 2>/dev/null
grep -n "slowlog\|SearchSlowLog\|IndexingSlowLog\|threshold" \
  server/src/main/java/org/opensearch/index/SearchSlowLog.java

Note: Slow-log thresholds are per shard, not per request. A search that hits 5 shards and is slow on only one logs once, for that shard. That is a feature: it tells you which shard is the laggard — often a hot shard or a cold one with an unwarmed page cache (see storage-engine).


Why is it stuck?

"Slow" means progress, just too little. "Stuck" means no progress: a request that never returns, a node that stops accepting work, a relocation that never finishes. The first call is _tasks, not a thread dump.

_tasks + cancellation

OpenSearch tracks in-flight work in a TaskManager. GET /_tasks lists every running task, its parent, the node, and how long it has run. This is how you find the one query that has been running for 40 seconds:

# All running tasks, with detail and runtime, grouped by parent:
curl -s 'localhost:9200/_tasks?detailed&group_by=parents' | python3 -m json.tool

# Just search tasks, sorted to find the long pole:
curl -s 'localhost:9200/_tasks?actions=*search*&detailed' | python3 -m json.tool

# A task shows running_time_in_nanos and the description (the query, for search).

When you find the culprit — a runaway aggregation, a scroll that's pinning segments, a reindex gone wrong — cancel it. Cancellation is cooperative: the task must check isCancelled() at safe points, which search and many bulk operations do.

# Cancel one task by id (node:taskNumber), or all of a kind:
curl -s -XPOST 'localhost:9200/_tasks/<node-id>:<task-number>/_cancel'
curl -s -XPOST 'localhost:9200/_tasks/_cancel?actions=*reindex*'
grep -n "class TaskManager\|isCancelled\|cancelTaskAndDescendants\|registerCancellable" \
  server/src/main/java/org/opensearch/tasks/TaskManager.java | head

Lab DP1 walks finding and cancelling a long task end to end.

Thread dumps — when nothing is progressing

If _tasks shows tasks that are stuck (running, but running_time not advancing across two calls), or the node isn't even answering _tasks, take a thread dump. A thread dump is a snapshot of every thread's stack and state — the ground truth of what the JVM is doing.

# Find the node PID (a ./gradlew run node, or a real install):
PID=$(jps -l | grep -i 'opensearch\|Bootstrap' | awk '{print $1}'); echo $PID

# Two equivalent ways to dump:
jstack -l "$PID" > /tmp/dump1.txt           # -l also lists owned locks
jcmd "$PID" Thread.print > /tmp/dump1.txt    # same content via the jcmd interface

# Take THREE dumps a few seconds apart -- one is a photo, three is a movie:
for i in 1 2 3; do jstack "$PID" > /tmp/dump$i.txt; sleep 5; done

What to look for, in priority order:

In the dumpMeans
"...[search][T#k]" ... java.lang.Thread.State: BLOCKED (on object monitor) and - waiting to lock <0x...>lock contention; find who - locked <0x...> that same monitor
Many [search]/[write] threads all BLOCKED on the same locka fixed pool is wedged — search/indexing stalls (see threadpools)
"clusterApplierService#updateTask" not WAITING for workthe applier thread is blocked — cluster state can't apply, the cluster manager may step down
Thread A waiting to lock X while holding Y, thread B waiting to lock Y while holding Xa classic deadlock — jstack prints a Found one Java-level deadlock summary

jstack detects deadlocks for you and prints a Found one Java-level deadlock: block at the end listing the cycle — that is the single most valuable line in the file. Lab DP3 builds and diagnoses a deadlock from a dump.

flowchart LR
    Stuck["request never returns"] --> T["GET _tasks?detailed"]
    T -->|"task present, time not moving"| D["jstack x3"]
    T -->|"runaway task"| Cancel["_tasks/<id>/_cancel"]
    D -->|"BLOCKED on monitor"| Lock["find the lock holder"]
    D -->|"deadlock summary"| DL["fix the lock ordering"]
    D -->|"all pool threads parked"| Star["pool starvation / blocking work on a fixed pool"]

Why is it OOM?

Heap pressure is the most dangerous failure: it degrades the whole node, then kills it. OpenSearch's first line of defense is circuit breakers (covered in circuit-breakers-memory) — they trip and reject a request before it OOMs the node. So the first question is not "where is the leak" but "is a breaker tripping, and which one?"

_nodes/stats — heap, breakers, and what's holding memory

# Heap usage and GC:
curl -s 'localhost:9200/_nodes/stats/jvm?filter_path=nodes.*.jvm.mem.heap_used_percent,nodes.*.jvm.gc' \
  | python3 -m json.tool

# Circuit breakers: tripped counts and current estimated bytes vs limit:
curl -s 'localhost:9200/_nodes/stats/breaker' | python3 -m json.tool

# The memory-hungry caches: fielddata, query cache, request cache, segments:
curl -s 'localhost:9200/_nodes/stats/indices/fielddata,query_cache,request_cache,segments' \
  | python3 -m json.tool
Breaker (org.opensearch.indices.breaker)Guards againstCommon trigger
parenttotal of all child breakers vs indices.breaker.total.limit (default ~95% heap, real-memory aware)overall heap pressure
fielddataheap held by field data for text/sorting/aggs on non-doc-valuesaggregating/sorting a text field
requestper-request data structures (agg BigArrays) vs indices.breaker.request.limita huge aggregation (high-cardinality terms)
in_flight_requestsbytes of in-flight transport/HTTP request bodieshuge bulk/search bodies
accountingmemory accounted after a request (e.g. Lucene segment readers)many large segments

A rising tripped count on request with a CircuitBreakingException in the logs is the textbook "my aggregation is too big" signal — the breaker did its job and protected the node. The fix is a smaller agg (size, partitions), not a bigger limit. See aggregations for MultiBucketConsumer and search.max_buckets.

Heap dumps → Eclipse MAT

When the heap is genuinely retained (a leak, or one giant structure) and breakers aren't catching it, take a heap dump and open it in Eclipse Memory Analyzer (MAT). This is heavy (the dump is roughly the size of the live heap, and writing it pauses the JVM), so it is the last resort, not the first.

# Trigger on OOM automatically (set in jvm.options / JVM args BEFORE the crash):
#   -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/lib/opensearch/heapdumps

# Or take one on demand from a live (struggling) node:
jcmd "$PID" GC.heap_dump /tmp/heap.hprof          # preferred, uses the JVM's own writer
jmap -dump:live,format=b,file=/tmp/heap.hprof "$PID"   # ":live" forces a GC first

In MAT, work top-down:

MAT viewWhat it answers
Leak Suspects reportMAT's automatic guess: "X is keeping N% of the heap alive via Y"
Dominator Treesorted by retained size — the object that, if freed, frees the most. The real culprit lives here.
Histograminstances per class — millions of byte[]/BytesRef/long[] points at fielddata or BigArrays
Path to GC Roots (exclude weak/soft)why a suspected-leaked object is still reachable

For OpenSearch specifically, the usual heap-dump culprits are a large fielddata structure (you aggregated/sorted a text field — see docvalues-fielddata), a giant aggregation result tree, or a BigArrays-backed buffer that a query is still holding. Lab DP3 finds a retained fielddata structure in MAT's dominator tree.

GC logs — is it a leak or just thrash?

Before concluding "leak," check whether GC is keeping up. Enable unified GC logging:

# In jvm.options (the default OpenSearch config already enables a variant of this):
#   -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m
grep -n "Xlog:gc\|gc.log\|HeapDumpOnOutOfMemory" config/jvm.options

Read the log for the pattern, not single lines:

GC log patternDiagnosis
Pause Full collections that don't reclaim much; used-after stays higha genuine leak or undersized heap — heap dump time
Frequent young GCs, healthy reclaim, stable old gennormal churn — chase allocation rate (async-profiler -e alloc), not a leak
Long Pause times (seconds)GC pauses are the latency spike — too-large heap, or G1 region pressure

Lab DP3 reads a GC log alongside the heap dump so you can tell thrash from leak.


Why is it wrong?

A wrong result (a count off by one, a missing bucket, a mis-scored doc) is a different discipline from a performance problem. You are not measuring; you are narrowing. Three tools, in order.

TRACE logging

OpenSearch uses Log4j2; almost every interesting class has a logger you can crank to TRACE at runtime, no restart:

# Turn on TRACE for a specific package on a live cluster:
curl -s -XPUT 'localhost:9200/_cluster/settings' -H 'Content-Type: application/json' -d'
{ "transient": { "logger.org.opensearch.search.aggregations": "TRACE" } }'

# ... reproduce the wrong result, read the log, then TURN IT OFF (TRACE is a firehose):
curl -s -XPUT 'localhost:9200/_cluster/settings' -H 'Content-Type: application/json' -d'
{ "transient": { "logger.org.opensearch.search.aggregations": null } }'
# Find the logger name to target -- it's the class's package:
grep -rn "private static final Logger\|LogManager.getLogger" \
  server/src/main/java/org/opensearch/search/aggregations/ | head

Warning: TRACE on a busy logger can produce gigabytes a minute and itself slow the node enough to change behavior (a Heisenbug). Scope it to the narrowest package, reproduce once, and turn it off immediately. Prefer a single-shard test index so the log is readable.

A deterministic reproducer

You cannot debug what you cannot reproduce on demand. The goal is a script or test that fails every time:

  • A curl script that creates a tiny index, indexes known docs, runs the query, and diffs the result against the expected JSON.
  • A failing OpenSearchIntegTestCase / AggregatorTestCase — the gold standard, because it runs in the build and git bisect can drive it. OpenSearch tests are randomized; pin the randomness so the failure is stable:
# Pin the random seed so the test takes the SAME path every run:
./gradlew :server:test --tests "org.opensearch.search.aggregations.MyAggTests" \
  -Dtests.seed=DEADBEEFCAFE -Dtests.iters=1

A reproducer that fails deterministically is 80% of the fix. Lab DP4 builds one and pins the seed.

git bisect — find the PR that introduced it

If the bug is a regression (it worked in 2.11, it's broken in 2.15), git bisect finds the introducing commit in O(log n) steps by binary-searching the history with your reproducer as the test:

git bisect start
git bisect bad  main                 # current HEAD is broken
git bisect good 2.11.0               # this tag was fine
# git checks out the midpoint; run your reproducer and tell it the verdict:
git bisect run ./gradlew :server:test --tests "...MyAggTests" -Dtests.seed=DEADBEEFCAFE
# bisect converges on the first BAD commit -> read its PR and the GitHub discussion.
git bisect reset

The payoff is the introducing PR — its description, review comments, and linked issue usually tell you why the change was made, which is half of how to fix it without re-breaking the original intent. Lab DP4 runs a full bisect across tags and reads the resulting PR.

./gradlew run --debug-jvm — step through it

When TRACE isn't enough, attach a real debugger. From an OpenSearch checkout:

# Start a node that suspends and waits for a debugger to attach on port 5005:
./gradlew run --debug-jvm
# It prints: "Listening for transport dt_socket at address: 5005"
# In IntelliJ: Run -> Attach to Process / a Remote JVM Debug config on localhost:5005.

# Debug a single TEST instead (suspends, waits on 5005):
./gradlew :server:test --tests "org.opensearch.search.aggregations.MyAggTests" --debug-jvm

Set a breakpoint in the suspect collect() / reduce() / toQuery() method, hit it with your reproducer, and inspect the live state. Lab DP4 attaches on 5005 and steps through a real code path.


The JVM tooling table

These are the off-the-shelf JVM tools the sections above lean on. They ship with the JDK (except async-profiler) and attach to any running JVM by PID.

ToolInvocationGives youUse for
jpsjps -lPIDs + main classes of running JVMsfinding the node PID
jstackjstack -l <pid>thread dump + lock ownership + deadlock detection"why is it stuck?"
jcmdjcmd <pid> <command>the swiss-army diagnostic: Thread.print, GC.heap_dump, JFR.start/dump, VM.flags, GC.class_histogrameverything; the modern front door
jmapjmap -histo:live <pid> / -dump:live,...class histogram / full heap dumpOOM / retention
jstatjstat -gcutil <pid> 1slive GC stats every secondquick "is GC the problem?"
JFR-XX:StartFlightRecording=... or jcmd <pid> JFR.startlow-overhead always-on recording: CPU, alloc, locks, I/O, GCcontinuous + post-hoc profiling
async-profilerasprof -e cpu/-e alloc/-e lock -d 30 -f flame.html <pid>accurate sampling flame graphs (CPU, allocations, locks)CPU/alloc hotspots, beats JFR for native frames
GC logs-Xlog:gc*:file=gc.logfull GC event logleak vs thrash
# jcmd is the front door -- list everything a live node supports:
jcmd "$PID" help
# A fast class histogram without a full dump (top heap consumers by class):
jcmd "$PID" GC.class_histogram | head -30

JFR and async-profiler are the heavy hitters; Lab DP2 drives both against a live node under load and reads the flame graphs.


The in-tree telemetry framework

Everything above is external tooling. OpenSearch also ships an internal observability layer under org.opensearch.telemetry — distributed tracing and a metrics framework — and as a contributor you will sometimes need to add a span or a metric to make a code path observable. This is the production successor to "add a log line."

find . -path "*telemetry*" -name "*.java" | grep -iE "Tracer|Span|MetricsRegistry|Counter|Histogram" | head
grep -rn "interface Tracer\|interface Span\|class SpanScope\|interface MetricsRegistry" \
  libs/telemetry/src/main/java/org/opensearch/telemetry/ 2>/dev/null | head

Tracing: Tracer / Span / SpanScope

Type (org.opensearch.telemetry.tracing.*)Role
Tracerthe entry point: startSpan(SpanCreationContext) opens a span; the no-op tracer is used when tracing is off
Spanone unit of work with a start/end, a parent, attributes (addAttribute), and events
SpanScopemakes a span "current" on the thread (try-with-resources) so child spans nest under it
SpanContextthe propagatable identity (trace id, span id) carried across threads/nodes via ThreadContext

The OpenTelemetry implementation lives in the telemetry-otel plugin (plugins/telemetry-otel), which exports spans via OTLP to a collector. The core only depends on the Tracer/Span interfaces; the plugin provides the real exporter. Tracing is gated by cluster settings (e.g. telemetry.tracer.enabled, with sampling settings) so it costs nothing when off.

Adding a span around code you are profiling:

// Inject the Tracer (it's available to components via the plugin/Node wiring).
import org.opensearch.telemetry.tracing.Tracer;
import org.opensearch.telemetry.tracing.Span;
import org.opensearch.telemetry.tracing.SpanScope;
import org.opensearch.telemetry.tracing.SpanCreationContext;

Span span = tracer.startSpan(SpanCreationContext.internal().name("agg.collect"));
try (SpanScope scope = tracer.withSpanInScope(span)) {
    span.addAttribute("agg.type", "terms");
    span.addAttribute("field", fieldName);
    // ... the work you want to time / trace ...
} catch (Exception e) {
    span.setError(e);
    throw e;
} finally {
    span.endSpan();
}

Metrics: MetricsRegistry / Counter / Histogram

The metrics framework is the counterpart for aggregate numbers — counts and distributions, not per-request spans:

Type (org.opensearch.telemetry.metrics.*)Use for
MetricsRegistrythe factory: createCounter(name, desc, unit), createHistogram(...), async gauges
Countera monotonically increasing (or up/down) count — add(value, Tags)
Histograma distribution of recorded values — record(value, Tags) (e.g. latencies)
Tagsdimensions attached to a measurement (index, shard, node) for slicing
import org.opensearch.telemetry.metrics.MetricsRegistry;
import org.opensearch.telemetry.metrics.Counter;
import org.opensearch.telemetry.metrics.Histogram;
import org.opensearch.telemetry.metrics.tags.Tags;

// Created once, at component construction:
Counter   rejected = metricsRegistry.createCounter("search.rejected.count",
                          "rejected search tasks", "1");
Histogram collectMs = metricsRegistry.createHistogram("agg.collect.latency",
                          "per-shard agg collect time", "ms");

// On the hot path:
rejected.add(1.0, Tags.create().addTag("index", indexName));
collectMs.record(elapsedMs, Tags.create().addTag("agg", "terms"));

How a stat surfaces in _nodes/stats

The telemetry framework (OTLP export) is separate from the node stats path you hit with GET /_nodes/stats. Those classic stats are wired differently: a subsystem implements a *Stats object that is Writeable + ToXContent, the node's NodeService/*Service collects it, and NodesStatsRequest/NodeStats serializes it into the REST response. When you add a new counter that should show up in _nodes/stats, you extend the relevant Stats class and its serialization, not the telemetry registry.

# How an existing stat flows from a service into _nodes/stats:
grep -rn "implements Writeable\|implements ToXContent\|class .*Stats" \
  server/src/main/java/org/opensearch/index/search/stats/SearchStats.java | head
grep -rn "class NodeStats\|class NodesStatsRequest\|toXContent" \
  server/src/main/java/org/opensearch/action/admin/cluster/node/stats/ | head
flowchart LR
    Code["your code path"] -->|"span"| Tracer["Tracer.startSpan"]
    Code -->|"counter/histogram"| MR["MetricsRegistry"]
    Tracer --> OTel["telemetry-otel plugin"]
    MR --> OTel
    OTel -->|"OTLP"| Collector["external collector (Jaeger/Prometheus)"]

    Code2["subsystem *Stats"] -->|"Writeable + ToXContent"| NS["NodeStats"]
    NS -->|"GET _nodes/stats"| REST["REST response"]

Note: Distinguish the two. Telemetry (Tracer/MetricsRegistry) is the newer, OTel-based, exported-to-a-collector path, gated by telemetry.* settings. Node stats (_nodes/stats) is the built-in, always-on, in-cluster path via Writeable/ToXContent. A new metric goes in one or the other depending on who consumes it.


Common bugs and symptoms

SymptomLikely causeFirst tool
One node pinned at 100% CPUa hot query/agg, or a tight loop_nodes/hot_threads?type=cpu
A specific query is slow, others fineexpensive clause/collector/agg in that query_search {"profile":true}
Latency creeping up cluster-wideGC pauses, or page-cache cold after restartjstat -gcutil / GC log; storage-engine
Request never returnsa stuck/runaway task_tasks?detailed → cancel; then jstack
429 rejected_executiona fixed pool's queue is full (back-pressure)_cat/thread_pool (threadpools)
Node stops serving search, search pool pinnedblocking work submitted to the SEARCH fixed pooljstack — find the blocked [search] threads
Cluster loses its cluster manager under loadan applier/listener blocked the applier threadjstack on clusterApplierService
CircuitBreakingException on an aggregationthe request breaker tripped (the agg is too big)_nodes/stats/breaker; circuit-breakers
OutOfMemoryError, heap fullretained fielddata / giant agg / leakheap dump → MAT dominator tree
GC runs constantly, reclaims littleleak or undersized heapGC log + heap dump
Wrong agg result only with concurrency onnon-associative reduce in a CollectorManagerTRACE + concurrent-segment-search
Test fails ~1 in 20 runsa flaky test (ordering/timing/seed)pin -Dtests.seed; stage-9-flaky-tests
It worked last release, broken nowa regressiongit bisect 2.x..main

Reading exercise

# 1. The built-in sampling profiler.
find server -name HotThreads.java
grep -n "type\|interval\|isIdleThread\|busiest" \
  server/src/main/java/org/opensearch/action/admin/cluster/node/hotthreads/HotThreads.java

# 2. Task tracking and cancellation.
grep -n "isCancelled\|cancelTaskAndDescendants\|registerCancellable" \
  server/src/main/java/org/opensearch/tasks/TaskManager.java

# 3. Slow logs.
grep -n "threshold\|SearchSlowLog\|reformat\|source" \
  server/src/main/java/org/opensearch/index/SearchSlowLog.java

# 4. The telemetry interfaces.
grep -rn "interface Tracer\|interface Span\|interface MetricsRegistry\|interface Counter\|interface Histogram" \
  libs/telemetry/src/main/java/org/opensearch/telemetry/

# 5. A live triage pass.
curl -s 'localhost:9200/_nodes/hot_threads?threads=5'
curl -s 'localhost:9200/_tasks?detailed&group_by=parents' | python3 -m json.tool
curl -s 'localhost:9200/_nodes/stats/breaker' | python3 -m json.tool

Answer:

  1. For each symptom — slow, stuck, OOM, wrong — name the first tool you reach for and why it's the cheapest one that narrows the problem.
  2. Read a hot_threads line: what does the thread name tell you, what does N/10 snapshots sharing mean, and what does type=block vs type=cpu change?
  3. In a Profile API response, what is the difference between build_scorer, next_doc, and score, and why are the absolute numbers untrustworthy?
  4. Why is _tasks the right first call for a stuck request, and what makes task cancellation cooperative?
  5. Walk a heap-dump investigation in MAT: which view do you open first, and what does "retained size" in the dominator tree mean?
  6. Contrast the telemetry framework (Tracer/MetricsRegistry) with the _nodes/stats path: which is exported to a collector, which is always-on, and where does a new metric go?
  7. Describe a full git bisect run: what good/bad mark, what the reproducer is, and what the payoff (the introducing PR) gives you.

Validation: prove you understand this

  • Given a node pinned at 100% CPU, produce the exact hot_threads call, read a stack, and name the pool and the suspected code path from the thread name + frames.
  • Run one query with "profile": true, point to the dominant breakdown field, and explain what it measures and why the absolute nanos are inflated.
  • Enable a search slow log, trip it, find the line, and explain why the threshold is per-shard.
  • Find a long-running task via _tasks, cancel it, and explain why cancellation is cooperative.
  • From a jstack dump, identify a BLOCKED thread, find the lock holder, and (in Lab DP3) read a Found one Java-level deadlock summary.
  • Take a heap dump, open the dominator tree in MAT, and name the retained-memory culprit and why it's still reachable.
  • Distinguish a breaker trip (_nodes/stats/breaker) from an OOM, and say which one means "the system protected itself."
  • Add a Counter or a Span to a code path, build, and explain where it surfaces (OTLP collector vs _nodes/stats).
  • Run a git bisect from a good tag to a bad main with a pinned-seed reproducer and name the introducing PR.

The labs: DP1 hot_threads & Profile API · DP2 JFR & async-profiler · DP3 Heap & Thread Dumps · DP4 Reproduce & Bisect.