Lab 7.1: Trace a Search Through Query and Fetch Phases

Background

A _search request travels through more layers than any other request in OpenSearch. It enters as HTTP, is parsed into a SearchRequest, fans out from the coordinating node to every target shard, runs a query phase on each shard, is reduced on the coordinator, fans out again for a fetch phase, and is assembled into a SearchResponse. If you cannot point at the class and method for each of those hops, you cannot debug a search bug, a slow query, or a partial failure.

This is a timed code-reading trace. You will not modify code. You will follow a single search from REST to response, leaving a grep trail at every hop, and then correlate your trace with the Profile API so the abstract phases become concrete timings on a real cluster.

Why This Lab Matters for Contributors

  • Search bugs are reported as "wrong results" or "slow" — both require you to know which phase.
  • Partial failures (_shards.failed > 0) only make sense if you know the fan-out.
  • Pagination cost (from/size/search_after) is invisible until you see the reduce.
  • Almost every search PR touches one of these five classes. You must read them before you change them.

Prerequisites

  • A built OpenSearch checkout (Level 1). Confirm ./gradlew assemble succeeds.
  • The ability to run a local node: ./gradlew run (single-node, REST on :9200).
  • Level 7 index read, especially the query-then-fetch diagram.
  • Recommended reading alongside: Search Execution deep dive.

Set up a shell variable so the curls are copy-pasteable:

export OS=http://localhost:9200

Step-by-Step Tasks

This lab is timed: aim for 90 minutes. Each step has a target time. If you blow past it, write down where you got stuck — that confusion is the lab's real output.

Step 1 — Spin up a cluster and index sample data (10 min)

./gradlew run

In a second terminal, create an index with a few shards so the fan-out is real (a single-shard index hides the scatter-gather):

curl -s -XPUT "$OS/flights" -H 'Content-Type: application/json' -d '{
  "settings": { "number_of_shards": 3, "number_of_replicas": 0 },
  "mappings": { "properties": {
    "carrier":  { "type": "keyword" },
    "dest":     { "type": "keyword" },
    "delay_min":{ "type": "integer" },
    "ts":       { "type": "date" }
  }}
}'

for i in $(seq 1 50); do
  curl -s -XPOST "$OS/flights/_doc" -H 'Content-Type: application/json' -d "{
    \"carrier\":\"C$((RANDOM%4))\",\"dest\":\"D$((RANDOM%6))\",
    \"delay_min\":$((RANDOM%120)),\"ts\":\"2026-06-$((1+RANDOM%15))T00:00:00Z\"
  }" >/dev/null
done
curl -s -XPOST "$OS/flights/_refresh" >/dev/null
echo "indexed"

Run a baseline search and keep the response open in another buffer:

curl -s "$OS/flights/_search?size=5&sort=delay_min:desc" \
  -H 'Content-Type: application/json' -d '{ "query": { "range": { "delay_min": { "gte": 30 } } } }' | head -40

Step 2 — Hop 1: REST parsing in RestSearchAction (10 min)

The HTTP request is handled by a RestHandler. Find it:

grep -rn "class RestSearchAction" server/src/main/java/org/opensearch/rest/action/search/
grep -n "_search" server/src/main/java/org/opensearch/rest/action/search/RestSearchAction.java | head

Read prepareRequest(...) and parseSearchRequest(...). Answer in your reading log:

  • Which method maps the URL params (from, size, search_type, scroll) onto the SearchRequest/SearchSourceBuilder?
  • Where does the request body JSON get parsed into a SearchSourceBuilder? (look for SearchSourceBuilder.fromXContent or parseSearchSource).
  • What ActionType is dispatched? (grep for client.execute( / SearchAction.INSTANCE.)
grep -n "SearchAction" server/src/main/java/org/opensearch/rest/action/search/RestSearchAction.java

Step 3 — Hop 2: coordinating node fan-out in TransportSearchAction (20 min)

This is the heart of the coordinating node. Locate it:

grep -rn "class TransportSearchAction" server/src/main/java/org/opensearch/action/search/

Read doExecute(...) and follow it into the search phase machinery. The fan-out is implemented as a sequence of SearchPhase objects. Grep for the phase classes:

ls server/src/main/java/org/opensearch/action/search/ | grep -i "Phase\|SearchAction\|Controller"

You are looking for the abstract async search phase driver (often AbstractSearchAsyncAction) and concrete phases. Trace these questions:

  • How does the coordinator decide which shards to target? (index resolution → RoutingTable → GroupShardsIterator<SearchShardIterator>). Grep:
    grep -rn "SearchShardIterator\|GroupShardsIterator" server/src/main/java/org/opensearch/action/search/ | head
    
  • Where is the can_match pre-filter phase? It can prune shards before the query phase:
    grep -rn "CanMatch\|canMatch" server/src/main/java/org/opensearch/action/search/ | head
    
  • What is the difference between query_then_fetch and dfs_query_then_fetch in the dispatch?
    grep -rn "DFS_QUERY_THEN_FETCH\|QUERY_THEN_FETCH" server/src/main/java/org/opensearch/action/search/SearchType.java
    

Note: The coordinating node never holds the documents during the query phase — it holds SearchPhaseResult objects containing top doc IDs, scores, sort values, and aggregation partials. Confirm this by reading what the query-phase results class carries:

grep -rn "class QuerySearchResult" server/src/main/java/org/opensearch/search/query/

Step 4 — Hop 3: the per-shard query phase (15 min)

The fan-out lands on each target shard at SearchService. Find the entry point:

grep -n "executeQueryPhase" server/src/main/java/org/opensearch/search/SearchService.java | head

Follow executeQueryPhase into QueryPhase:

grep -rn "class QueryPhase" server/src/main/java/org/opensearch/search/query/
grep -n "execute\|executeInternal\|TopDocs\|collector" server/src/main/java/org/opensearch/search/query/QueryPhase.java | head -30

Answer:

  • Where is the SearchContext/DefaultSearchContext created, and what does it hold? (the Lucene IndexSearcher, the parsed Query, the from/size, the aggregators).
    grep -rn "class DefaultSearchContext" server/src/main/java/org/opensearch/search/internal/
    
  • Where does the QueryBuilder become a Lucene Query? (look for searchContext.query() set via QueryShardContext.toQuery).
  • How many docs does each shard collect for a request of from=10000&size=10? (answer: top from + size = 10010 — this is the deep-pagination cost).

Step 5 — Hop 4: the coordinating-node reduce in SearchPhaseController (10 min)

After all shards return their query results, the coordinator merges them:

grep -rn "class SearchPhaseController" server/src/main/java/org/opensearch/action/search/
grep -n "reducedQueryPhase\|sortDocs\|merge" server/src/main/java/org/opensearch/action/search/SearchPhaseController.java | head -20

This is where:

  • The global top size is computed from per-shard top-Ks (a merge of sorted lists).
  • Aggregations are reduced (InternalAggregations.reduce / InternalAggregation.reduce).
  • The coordinator decides which doc IDs on which shards must be fetched.

Find the agg reduce call:

grep -rn "InternalAggregation" server/src/main/java/org/opensearch/action/search/SearchPhaseController.java | head

Step 6 — Hop 5: the fetch phase (10 min)

Only winning docs are fetched. Entry point:

grep -n "executeFetchPhase" server/src/main/java/org/opensearch/search/SearchService.java | head
grep -rn "class FetchPhase" server/src/main/java/org/opensearch/search/fetch/

Answer:

  • What does FetchPhase load that the query phase did not? (_source, stored fields, highlights, script fields — via FetchSubPhase implementations).
    ls server/src/main/java/org/opensearch/search/fetch/subphase/
    
  • Why is the fetch fan-out usually smaller than the query fan-out? (only shards owning winners).

Step 7 — Correlate with the Profile API (15 min)

Now make the phases concrete. The Profile API instruments per-shard timings:

curl -s "$OS/flights/_search" -H 'Content-Type: application/json' -d '{
  "profile": true,
  "size": 5,
  "sort": [ { "delay_min": "desc" } ],
  "query": { "bool": { "must": [
    { "range": { "delay_min": { "gte": 30 } } },
    { "terms": { "carrier": ["C0","C1"] } }
  ]}},
  "aggs": { "by_carrier": { "terms": { "field": "carrier" } } }
}' > /tmp/profile.json

# How many shards reported? (this is your fan-out width)
grep -c '"shard_id"' /tmp/profile.json 2>/dev/null || python3 -c "import json;d=json.load(open('/tmp/profile.json'));print('shards:',len(d['profile']['shards']))"

Inspect one shard's profile. You will see the query rewritten into Lucene query nodes (BooleanQuery, IndexOrDocValuesQuery, TermInSetQuery), each with time_in_nanos broken into create_weight, build_scorer, next_doc, score, etc., plus a collector tree and an aggregations section.

python3 - <<'PY'
import json
d=json.load(open('/tmp/profile.json'))
sh=d['profile']['shards'][0]
print("shard:", sh['id'])
q=sh['searches'][0]['query'][0]
print("top query node:", q['type'], "time_ns:", q['time_in_nanos'])
print("collector:", sh['searches'][0]['collector'][0]['name'])
print("aggs:", [a['type'] for a in sh.get('aggregations',[])])
PY

Map what you see back onto your trace:

Profile sectionPhase you tracedClass
query rewrite treequery phase, query → LuceneQueryPhase, QueryShardContext.toQuery
collector treequery phase top-K collectionQueryPhase collectors
aggregationsper-shard collectAggregator
(not shown — coordinator-side)reduceSearchPhaseController

Note: The Profile API only shows per-shard work. The coordinator-side reduce and the fetch phase are not in the profile output. That gap is itself a lesson: profiling tells you about shard cost, not coordinator cost. Deep-pagination pain lives in the reduce, which the profile cannot see.


Pagination: from/size vs search_after (reading exercise)

Run all three and compare what the coordinator must do:

# Deep from/size — every shard must produce top 110 docs
curl -s "$OS/flights/_search?from=100&size=10&sort=delay_min:desc" -o /dev/null -w "from/size: %{http_code}\n"

# search_after — cursor by the last page's sort values (cheap, stateless)
LAST=$(curl -s "$OS/flights/_search?size=5&sort=delay_min:desc" | python3 -c "import json,sys;h=json.load(sys.stdin)['hits']['hits'];print(json.dumps(h[-1]['sort']))")
curl -s "$OS/flights/_search" -H 'Content-Type: application/json' -d "{
  \"size\":5, \"sort\":[{\"delay_min\":\"desc\"}], \"search_after\": $LAST }" -o /dev/null -w "search_after: %{http_code}\n"

In your log, explain: for from=10000, why does every shard pay, and why does search_after not? (Because from/size requires each shard to materialize the top from+size; search_after seeks each shard directly to the cursor and collects only size.)


Implementation Requirements

This is a reading/tracing lab. Your deliverable is a reading-log artifact — a Markdown file with one section per hop:

## Hop 1: RestSearchAction
- file: server/src/main/java/org/opensearch/rest/action/search/RestSearchAction.java
- grep used: grep -n "_search" .../RestSearchAction.java
- method: prepareRequest -> parseSearchRequest
- what crosses to next hop: a SearchRequest (with SearchSourceBuilder)

## Hop 2: TransportSearchAction  ... (etc for all five hops)

Each hop section must contain: the file path, the grep command you ran, the method, and what crosses the wire to the next hop.


Expected Output

  • A flights index with 3 shards and ~50 docs.
  • A Profile API JSON whose shard count equals your index's shard count.
  • A reading log covering all five hops plus the pagination exercise.
  • A clear statement of which two things the Profile API does not show (reduce, fetch).

Troubleshooting

SymptomCauseFix
_search returns _shards.total: 1Index has one shard; no fan-out to observeRecreate with number_of_shards: 3
Profile JSON has empty aggregationsNo aggs in the requestAdd the terms agg from Step 7
grep finds the class in test/ not main/You matched a testRestrict the path to server/src/main/java/
search_after returns the same pageWrong/stale sort cursorRe-read the last hit's sort array each page

Stretch Goals

  1. Add "explain": true to a search and correlate the BM25 explanation with the score timing in the profile. Where does the term frequency come from on a single shard?
  2. Force search_type=dfs_query_then_fetch and diff the scores against query_then_fetch on a multi-shard index. Explain the difference using the DfsPhase.
  3. Find where terminate_after short-circuits the query-phase collector:
    grep -rn "terminate_after\|terminateAfter" server/src/main/java/org/opensearch/search/ | head
    

Coding Exercises

The trace is worthless until you can encode it. These exercises turn each hop you read into executable proof. Locate every class with rg/grep first (the iron rule — never trust a remembered line number), then write the code.

  1. (warm-up) Write an OpenSearchTestCase (or AbstractWireSerializingTestCase) round-trip for QuerySearchResult that asserts the query phase carries no documents. Build a QuerySearchResult with TopDocs + sort values, serialize/deserialize it, and assert it holds doc IDs and scores but never a _source. Locate it:

    grep -rn "class QuerySearchResult" server/src/main/java/org/opensearch/search/query/
    

    This is the trace claim from Step 3 made into a regression guard.

  2. (core) Write an OpenSearchIntegTestCase that proves two-phase behavior. Create a 3-shard index, index a handful of docs, run a client().prepareSearch() with size, and assert response.getHits().getTotalHits() and the per-shard counts. Then add searchType(DFS_QUERY_THEN_FETCH) and assert the response still returns the same hits. Find the harness convention:

    grep -rln "extends OpenSearchIntegTestCase" server/src/test/java/org/opensearch/search/ | head
    
  3. (core) Instrument QueryPhase. Add a temporary logger.debug(...) (or a Counter) at the top of QueryPhase.execute/executeInternal that prints the shard id and the collected hit count, then write a test that captures it with MockLogAppender and asserts the line fired once per shard.

    grep -rn "class QueryPhase" server/src/main/java/org/opensearch/search/query/
    grep -rln "MockLogAppender" server/src/test/java/org/opensearch/ | head
    

    Deliver the instrumentation as a small patch (git diff) plus the capturing test. Revert the log line after; keep the test logic as your artifact.

  4. (core) A DfsPhase observation test. On a multi-shard index with deliberately skewed term frequencies, run the same query under query_then_fetch and dfs_query_then_fetch and assert the scores differ (DFS computes global term stats first). Locate the phase:

    grep -rn "class DfsPhase" server/src/main/java/org/opensearch/search/dfs/
    

    Assert the relative ordering or absolute score delta; explain in a comment why DFS changes BM25.

  5. (advanced) Advanced challenge — a can_match pruning assertion. Write an OpenSearchIntegTestCase that creates an index where one shard's range bounds cannot match the query (e.g. a range on a date field that one shard's min/max excludes), runs the search, and asserts via the SearchResponse that getSkippedShards() (the count can_match pruned) is > 0. Then add a doc that makes the shard matchable and assert skipped drops to zero. Locate:

    grep -rn "CanMatch\|canMatch\|getSkippedShards" server/src/main/java/org/opensearch/action/search/ | head
    

    This proves you understand the pre-filter phase end-to-end: a real, observable coordinator decision.

Issues to Practice On

Search-phase bugs live in opensearch-project/OpenSearch core; the area labels below are your filter (labels move; confirm on the tracker — run gh label list --repo opensearch-project/OpenSearch and pick).

GoalCommand
Search core, beginner-friendlygh issue list --repo opensearch-project/OpenSearch --label "good first issue" --label "Search" --state open
Any open search buggh issue list --repo opensearch-project/OpenSearch --label "bug" --label "Search" --state open
Relevance / scoring (DFS, BM25)gh issue list --repo opensearch-project/OpenSearch --label "Search:Relevance" --state open

Representative patterns. (1) A "wrong _shards.skipped / can_match" report: reproduce with a multi-shard index whose bounds exclude one shard, locate the decision via rg "canMatch" server/.../action/search, fix, and add an integ test that asserts the skipped count. (2) A "scores differ between query_then_fetch and dfs_query_then_fetch unexpectedly" report: reproduce → locate in DfsPhase/SearchPhaseController → fix → test. Approach every one the same way: reproduce → locate via rg → fix → test → PR with CHANGELOG + DCO sign-off.

Planted-bug drill. In your local checkout, find where the coordinator decides the fetch fan-out (the doc-IDs-per-shard selection in SearchPhaseController, e.g. fillDocIdsToLoad/getLastEmittedDocPerShard), and deliberately break it — for instance change the from + size window used to size the top-K merge, or off-by-one the doc-id collection. Run ./gradlew :server:test --tests "*SearchPhaseController*" and watch which test goes red. Then revert, and add one new assertion that pins the exact behavior the bug violated (e.g. "fetch targets exactly the winning doc IDs, no more"). Locate the seam first:

grep -rn "fillDocIdsToLoad\|getLastEmittedDocPerShard\|reducedQueryPhase" server/src/main/java/org/opensearch/action/search/SearchPhaseController.java | head

Etiquette: Claim an issue with a comment before working it, reproduce on main first, and every PR needs a test + a CHANGELOG.md entry + a DCO Signed-off-by (git commit -s). See community interaction and the level-2 PR lab.

Validation / Self-check

You are done when you can answer, without re-reading:

  1. Name the five classes, in order, that a _search passes through from REST to response.
  2. In the query phase, does a shard return documents? If not, what does it return?
  3. Why is from=10000&size=10 expensive, and which class pays the cost?
  4. What does the fetch phase load that the query phase did not, and why is its fan-out smaller?
  5. Where does a QueryBuilder become a Lucene Query, and what context object performs the conversion?
  6. What does can_match do, and which class implements it?
  7. Name two things the Profile API does not measure.

Cross-references: Search Execution deep dive, Query DSL and QueryBuilders, Lab 7.2: Aggregations, Capstone Step 2: Reproduction.