07c — Caching and query profiling

Two debugging and optimization tools you will reach for repeatedly: understanding which cache your query can use, and profiling to find the exact clause that is slow. This part explains how the three Elasticsearch caches work and when they help, then shows you how to use the _profile API and the slow query log.

Goals for this part

Understand the three caches: shard request cache, query (filter) cache, and fielddata cache
Know which query patterns benefit from caching — and which are traps
Use _profile: true to identify the slowest clause in a query
Use the Kibana Search Profiler and the slow query log for production diagnostics

7.4 Caching

Elasticsearch has three distinct caches relevant to query performance. Understanding what each one caches — and what it does not — determines whether optimising for cache hits is even possible.

Shard request cache

What it caches: the aggregation results (and hits.total) for queries with size: 0, per shard. If the exact same query hits the same shard and the shard has not been refreshed since the last time, the cached result is returned without executing the query.

Controlled by: the request_cache parameter on the request (defaults to true for size: 0 queries).

When it helps: dashboards and monitoring queries that run the same aggregation repeatedly on stable (or slowly-changing) data. Common in Kibana visualizations with fixed time ranges.

When it does not help: queries with now in the time range at millisecond precision (Elasticsearch normalises now to a minute-level bucket, so short-range now-15m queries can still hit cache if rounded correctly, but precise now disables it).

GET logs-read/_search?request_cache=true
{
  "size": 0,
  "query": {
    "range": { "@timestamp": { "gte": "now-1h/h", "lte": "now/h" } }
  },
  "aggs": {
    "errors_by_service": {
      "terms": { "field": "service", "size": 20 }
    }
  }
}

Inspect cache stats:

GET logs-read/_stats/request_cache

Query cache (node-level filter cache)

What it caches: the bitset of matching document IDs for individual filter clauses — not scores, not full results. Reused across queries that contain the same filter on the same shard.

Why filter context, not must: filters do not compute relevance scores, so Elasticsearch can cache the result as a simple bitset and reuse it. Queries in must context compute scores and are not cached this way. This is a direct reason to move exact-match and range constraints into bool.filter rather than bool.must — performance and cacheability both improve.

GET shop-orders-demo/_search
{
  "query": {
    "bool": {
      "must": [
        { "match": { "description": "premium" } }
      ],
      "filter": [
        { "term":  { "status": "completed" } },
        { "range": { "created_at": { "gte": "2024-01-01" } } }
      ]
    }
  }
}

The status and created_at filters are cached. The match on description is not.

Inspect:

GET _nodes/stats/indices/query_cache

Fielddata cache

What it caches: when a text field is used in an aggregation or sort, Elasticsearch must load all field values into the JVM heap (uninverted index). This is the fielddata cache.

The danger: fielddata for text fields can be enormous — it stores every token from every analyzed document. On a large index, this can consume gigabytes of heap, trigger circuit breakers, or cause OOM errors.

The fix: never aggregate or sort on text fields. Map fields that need both full-text search and aggregation as text with a keyword subfield:

PUT shop-orders-demo/_mapping
{
  "properties": {
    "customer_name": {
      "type": "text",
      "fields": {
        "keyword": { "type": "keyword" }
      }
    }
  }
}

Then aggregate on customer_name.keyword, not on customer_name. The keyword subfield uses doc_values (on-disk columnar storage), not fielddata — it does not consume heap.

Inspect fielddata:

GET _nodes/stats/indices/fielddata

If you see evictions climbing, fielddata is under pressure.

Summary of what actually helps: Put constraints in filter context (query cache). Use size: 0 aggregations on stable time windows (request cache). Map aggregation fields as keyword with doc_values (avoids fielddata entirely). These three changes cover 80% of practical cache wins.

7.5 Query profiling

When a query is slow and you need to understand why, Elasticsearch provides two tools: the _profile API and the slow query log.

The `_profile` API

Add "profile": true to any search request:

GET shop-orders-demo/_search
{
  "profile": true,
  "query": {
    "bool": {
      "filter": [
        { "term": { "status": "completed" } },
        { "range": { "created_at": { "gte": "2024-01-01" } } }
      ],
      "must": [
        { "match": { "description": "premium shipping" } }
      ]
    }
  },
  "aggs": {
    "by_status": {
      "terms": { "field": "status", "size": 10 }
    }
  }
}

The response includes a profile section per shard. Each shard profile contains:

searches — the query tree, broken down by clause. Each clause shows time_in_nanos, description (the Lucene query type), and breakdown (how time was split across build_scorer, next_doc, advance, etc.)
aggregations — time spent in each aggregation, per shard
collector — how results were collected

What to look for:

Symptom	Likely cause
One clause has disproportionately high time	Expensive query type (wildcard, script, unanalyzed term on text)
`build_scorer` dominates	The filter is not cached — first hit; will be fast on second
`next_doc` / `advance` high	Many documents match the query; consider narrowing scope
Aggregation time >> query time	High-cardinality terms agg, or aggregating on fielddata
Rewrite time high	Wildcard/regex query is expanding to many terms

Profile results are per shard — if you hit 20 shards, you get 20 profile trees. Look for the slowest shard, not just the average.

Search Profiler in Kibana Dev Tools

In Kibana, go to Dev Tools → Search Profiler (the tab next to Console). Paste your query and index pattern, run it. The UI renders the shard tree visually, with time bars for each clause — much easier to read than raw JSON for complex queries.

Use the Search Profiler in development and staging. In production, "profile": true adds overhead — use it on targeted diagnostic queries, not as a permanent flag.

Slow query log

The slow log catches offenders in production without modifying query code. Configure thresholds on an index:

PUT shop-orders-demo/_settings
{
  "index.search.slowlog.threshold.query.warn":  "5s",
  "index.search.slowlog.threshold.query.info":  "2s",
  "index.search.slowlog.threshold.query.debug": "500ms",
  "index.search.slowlog.threshold.fetch.warn":  "1s"
}

Any search that exceeds a threshold is logged to the Elasticsearch slow log file. The log entry includes the full query JSON, the shard it ran on, the took time, and the number of hits.

Strategy: 1. Start with high thresholds (e.g., warn at 5s) to avoid log volume. 2. Look for patterns: wildcard queries, missing time filters, large aggregations on high-cardinality fields. 3. Fix the patterns. Lower thresholds once the worst offenders are resolved.

To disable when done:

PUT shop-orders-demo/_settings
{
  "index.search.slowlog.threshold.query.warn": "-1"
}

Pitfall: Do not leave low thresholds (e.g., debug: 10ms) enabled permanently in production. The log volume causes its own IO pressure.

Lab — Caching and profiling slow queries

Part A: Understanding filter caching

Goal: See the effect of filter context vs must context on query cost.

Step 1 — Run a query with exact-match filters in must context (suboptimal):

GET /shop-orders-demo/_search
{
  "profile": true,
  "query": {
    "bool": {
      "must": [
        { "term":  { "order_status": "completed" } },
        { "term":  { "channel": "web" } },
        { "match": { "notes": "payment" } }
      ]
    }
  },
  "size": 0,
  "aggs": { "by_channel": { "terms": { "field": "channel" } } }
}

Note time_in_nanos for each clause in the profile output.

Step 2 — Rewrite: move the exact-match terms to filter context (optimal):

GET /shop-orders-demo/_search
{
  "profile": true,
  "query": {
    "bool": {
      "filter": [
        { "term": { "order_status": "completed" } },
        { "term": { "channel": "web" } }
      ],
      "must": [
        { "match": { "notes": "payment" } }
      ]
    }
  },
  "size": 0,
  "aggs": { "by_channel": { "terms": { "field": "channel" } } }
}

Run it twice. On the second run, does the filter clause show lower time_in_nanos? (The filter result may be cached after the first execution.)

Questions: 1. Which clauses produce scores in must but not in filter? 2. Why is filter context more cache-friendly?

Part B: Profiling a slow query

Goal: Identify and fix the most expensive clause using _profile.

Step 3 — Run this deliberately slow query with "profile": true:

GET /shop-orders-demo/_search
{
  "profile": true,
  "query": {
    "bool": {
      "must": [
        { "wildcard": { "order_status": "*end*" } }
      ]
    }
  },
  "aggs": {
    "by_status": {
      "terms": { "field": "order_status", "size": 50 }
    }
  }
}

In the profile output, find: 1. The clause with the highest time_in_nanos 2. What Lucene query type is the wildcard compiled to?

Step 4 — Fix the query: move order_status to bool.filter, and replace the wildcard with an exact term query:

GET /shop-orders-demo/_search
{
  "profile": true,
  "query": {
    "bool": {
      "filter": [
        { "term": { "order_status": "pending" } }
      ]
    }
  },
  "size": 0,
  "aggs": {
    "by_status": {
      "terms": { "field": "order_status", "size": 10 }
    }
  }
}

Compare the time_in_nanos for the fixed query. Is it significantly faster?

Step 5 — Open Kibana Dev Tools → Search Profiler (the tab next to the Console). Paste the slow query from Step 3, run it. Compare the visual tree vs reading the raw JSON profile.

Step 6 — Configure slow query logging on shop-orders-demo for anything over 100ms:

PUT /shop-orders-demo/_settings
{
  "index.search.slowlog.threshold.query.warn":  "100ms",
  "index.search.slowlog.threshold.query.info":   "50ms"
}

Run the wildcard query from Step 3 a few times. In a production environment, you would then check the Elasticsearch log file for slow query entries. Then disable the threshold:

PUT /shop-orders-demo/_settings
{
  "index.search.slowlog.threshold.query.warn": "-1",
  "index.search.slowlog.threshold.query.info": "-1"
}

Step 7 — Check the request cache stats for shop-orders-demo:

GET /shop-orders-demo/_stats/request_cache

Run a size: 0 aggregation query twice and re-check the stats. Did hit_count increase?

GET /shop-orders-demo/_search?request_cache=true
{
  "size": 0,
  "query": { "term": { "order_status": "completed" } },
  "aggs": { "by_channel": { "terms": { "field": "channel" } } }
}

Takeaway: _profile shows exactly which clause costs the most. Moving exact matches to filter context almost always wins — it’s the single highest-impact query change. The Kibana Search Profiler makes the profile tree easy to read. The slow query log catches production offenders without touching query code.