Lab K2: Trace a k-NN Query

Background

You can build the plugin (Lab K1) and you have read the query-path chapter. This lab makes that chapter yours by forcing you to find every hop in the live source, with a stopwatch running. A knn query travels a long way: REST body → KNNQueryBuilder → a per-shard Lucene Query (KNNQuery for native engines, a Lucene vector query for the lucene engine) → KNNWeight per segment → either a native faiss search across the JNI boundary or Lucene's own HNSW search → a top-k collect per shard → a final merge on the coordinating node.

This is a timed code-reading trace. You will set a 75-minute timer, grep your way down the call chain one hop at a time, capture a one-line note per hop in a reading-log artifact, and corroborate each hop against two runtime signals: the _search?profile=true output and TRACE-level logging from the k-NN query package. The discipline is the point: you are training the muscle that lets you land in an unfamiliar subsystem and orient in an hour, which is exactly what triaging a real k-NN issue demands.

Note: The cluster manager (formerly master) owns cluster state but is not on the hot path of a search. The query fan-out is coordinated by whichever node received the request (the coordinating node), which need not be the cluster manager. Keep these two roles separate as you trace; conflating them is a common early mistake.

This lab leans on two existing chapters — keep them open:

The k-NN query path — the narrative version of what you are about to verify in source.
Search execution — the core query/fetch fan-out that k-NN slots into; the per-shard query phase and coordinator reduce are core mechanics, not k-NN ones.

Why This Lab Matters for Contributors

Most k-NN issues are reported as a query symptom ("recall dropped", "filter ignored", "slower than expected", "wrong scores"). You cannot triage any of them without being able to trace the query path to the exact hop where behavior diverges.
The native (faiss) and Lucene (lucene) engines fork on the query path. Knowing where they diverge — and that one crosses JNI while the other stays in pure Java — is the single most load-bearing fact for debugging engine-specific behavior.
profile=true and TRACE logging are the two tools that turn a guess into evidence. Pairing a static code read with both runtime signals is how senior engineers confirm a hypothesis instead of arguing about it.
A reading-log artifact is reusable: drop it into an issue comment or a PR description and you have just made a reviewer's life easier and your analysis legible.

Prerequisites

A running node built from Lab K1 (./gradlew run is fine), with the k-NN plugin loaded.
The k-NN source checkout open in your editor; you will grep it constantly.
Familiarity with the query-path chapter — read it once before timing yourself.
A timer. Seriously. The constraint is what builds the skill.

# Orient yourself in the query package before the clock starts:
cd ~/src/oss-repos/k-NN
ls src/main/java/org/opensearch/knn/index/query/
#   KNNQueryBuilder.java  KNNQuery.java  KNNWeight.java  DefaultKNNWeight.java
#   KNNScorer.java  KNNQueryFactory.java  lucene/  lucenelib/  nativelib/  exactsearch/  rescore/ ...

Step-by-Step Tasks

Step 0: Set up the index and the reading log (5 min, off the clock)

Create one faiss index and one lucene index so you can trace both forks against real data.

# Native (faiss) engine:
curl -s -XPUT 'localhost:9200/trace_faiss?pretty' -H 'Content-Type: application/json' -d '{
  "settings": { "index.knn": true },
  "mappings": { "properties": {
    "v": { "type": "knn_vector", "dimension": 3,
           "method": { "name": "hnsw", "engine": "faiss", "space_type": "l2" } }
  }}
}'

# Lucene engine (pure-Java path, no JNI):
curl -s -XPUT 'localhost:9200/trace_lucene?pretty' -H 'Content-Type: application/json' -d '{
  "settings": { "index.knn": true },
  "mappings": { "properties": {
    "v": { "type": "knn_vector", "dimension": 3,
           "method": { "name": "hnsw", "engine": "lucene", "space_type": "l2" } }
  }}
}'

for idx in trace_faiss trace_lucene; do
  curl -s -XPOST "localhost:9200/$idx/_bulk?refresh=true" -H 'Content-Type: application/x-ndjson' -d '
{ "index": {"_id":"1"} }
{ "v": [1,1,1] }
{ "index": {"_id":"2"} }
{ "v": [2,2,2] }
{ "index": {"_id":"3"} }
{ "v": [9,9,9] }
'
done

Create the artifact you will fill in. A plain Markdown table is enough:

cat > ~/knn-query-reading-log.md <<'EOF'
# k-NN Query Reading Log — Lab K2

| Hop | File:method | What happens here | Evidence (grep/profile/TRACE) |
|-----|-------------|-------------------|-------------------------------|
| 0 REST | | | |
| 1 Builder->Query | | | |
| 2 Weight (per seg) | | | |
| 3a native (faiss/JNI) | | | |
| 3b lucene (KnnFloatVectorQuery) | | | |
| 4 per-shard top-k | | | |
| 5 coordinator reduce | | | |
EOF

Step 1: Turn on the evidence channels — `profile` and `TRACE` (start the timer)

Start your 75-minute timer now. First, enable both runtime signals so every hop you read in source has a corroborating fact.

# (a) Profile a query: per-component timing in the response, no logging needed.
curl -s -XPOST 'localhost:9200/trace_faiss/_search?profile=true&pretty' \
  -H 'Content-Type: application/json' -d '{
  "size": 2,
  "query": { "knn": { "v": { "vector": [1.1, 0.9, 1.0], "k": 2 } } }
}' | sed -n '1,80p'
# Look in the "profile" -> "shards" -> "searches" -> "query" array for the rewritten
# query class name (this is your proof of which Query implementation ran).

# (b) Crank TRACE logging for the k-NN query package (dynamic, no restart):
curl -s -XPUT 'localhost:9200/_cluster/settings' -H 'Content-Type: application/json' -d '{
  "transient": { "logger.org.opensearch.knn.index.query": "TRACE" }
}'

Record in the log (Hop 0): the REST entry point. Find where the knn query name is registered and parsed.

grep -rn "public static final String NAME = \"knn\"\|fromXContent\|VECTOR_FIELD\|K_FIELD" \
  src/main/java/org/opensearch/knn/index/query/KNNQueryBuilder.java | head
# NAME = "knn"  -> registered via SearchPlugin.getQueries() in KNNPlugin (grep getQueries)
grep -rn "getQueries\|new QuerySpec\|KNNQueryBuilder::new\|KNNQueryBuilder::fromXContent" \
  src/main/java/org/opensearch/knn/plugin/KNNPlugin.java

Step 2: Hop 1 — `KNNQueryBuilder` → a per-shard `Query`

The builder validates the request against the field mapping and produces the Lucene Query. The single most important branch in the whole path lives here: which engine?

# The core conversion method (grep for the line, don't trust a number):
grep -n "doToQuery\|QueryShardContext\|class KNNQueryBuilder" \
  src/main/java/org/opensearch/knn/index/query/KNNQueryBuilder.java
#   protected Query doToQuery(QueryShardContext context)

# doToQuery delegates the engine fork to a factory. Find it:
grep -rn "KNNQueryFactory\|createKNNQuery\|class KNNQueryFactory" \
  src/main/java/org/opensearch/knn/index/query/ | head

Open KNNQueryFactory and read the fork. This is where native and lucene diverge:

grep -n "LuceneEngineKnnVectorQuery\|OSKnnFloatVectorQuery\|OSKnnByteVectorQuery\|new KNNQuery\|KNNEngine\|isLuceneEngine\|getEngine" \
  src/main/java/org/opensearch/knn/index/query/KNNQueryFactory.java

Engine	Query class produced	Path from here
`faiss` / `nmslib` (native)	`KNNQuery`	→ `KNNWeight`/`DefaultKNNWeight` → JNI faiss search
`lucene`	`LuceneEngineKnnVectorQuery` wrapping `OSKnnFloatVectorQuery`/`OSKnnByteVectorQuery` (extends Lucene's `KnnFloatVectorQuery`/`KnnByteVectorQuery`)	→ Lucene's own HNSW search, pure Java, no JNI

Record in the log (Hop 1): KNNQueryBuilder.doToQuery → KNNQueryFactory → which Query class for each engine. Evidence: the profile=true output names the rewritten query class — confirm faiss shows a KNNQuery-family class and lucene shows a vector-query class.

Note: The lucene engine's queries extend Lucene's KnnFloatVectorQuery / KnnByteVectorQuery (see org.opensearch.knn.index.query.lucenelib). That means the entire search for the lucene engine is executed by Lucene's HNSW code — the same code path described in HNSW in Lucene — with k-NN only wrapping it to add filtering/score semantics. There is no k-NN native code on the lucene fork.

Step 3: Hop 2 — `KNNQuery` → `KNNWeight` per segment

A Lucene Query is turned into a Weight, and the Weight produces a per-segment scorer. For the native fork this is KNNWeight (abstract) with DefaultKNNWeight as the concrete implementation.

grep -n "class KNNWeight\|createWeight\|public Scorer scorer\|searchLeaf\|abstract" \
  src/main/java/org/opensearch/knn/index/query/KNNWeight.java | head
grep -n "class DefaultKNNWeight\|doANNSearch\|protected TopDocs" \
  src/main/java/org/opensearch/knn/index/query/DefaultKNNWeight.java | head

The key method is searchLeaf (per LeafReaderContext = per segment). Read it: it decides between approximate (ANN) search and an exact brute-force fallback, applies any filter as a BitSet, and returns per-leaf TopDocs.

grep -n "searchLeaf\|doANNSearch\|exactSearch\|ExactSearcher\|filterWeight\|BitSet\|canDoExactSearch\|cardinality" \
  src/main/java/org/opensearch/knn/index/query/KNNWeight.java | head -20

Record in the log (Hop 2): KNNWeight.searchLeaf — the per-segment entry, and the ANN-vs-exact branch. Evidence: in the TRACE log you will see per-segment search messages; in profile=true the time is attributed to the query's score/build_scorer breakdown.

Step 4: Hop 3a — the native faiss search across JNI

For a faiss field, doANNSearch is where Java leaves the JVM. It obtains the loaded native graph from the cache, then calls JNI to run the top-k search.

grep -n "doANNSearch\|JNIService\|FaissService\|queryIndex\|NativeMemoryCacheManager\|getIndexAllocation\|loadGraph" \
  src/main/java/org/opensearch/knn/index/query/DefaultKNNWeight.java | head
# The JNI dispatch:
grep -rn "queryIndex\|public static native" \
  src/main/java/org/opensearch/knn/jni/JNIService.java \
  src/main/java/org/opensearch/knn/jni/FaissService.java | head

The chain is: DefaultKNNWeight.doANNSearch → NativeMemoryCacheManager (load or reuse the graph, on a cache miss FaissService.loadIndex) → JNIService.queryIndex → FaissService.queryIndex (native) → C++ faiss::Index::search → results marshalled back as KNNQueryResult[] → KNNScorer translates each distance to a Lucene score via the SpaceType.

grep -n "class KNNScorer\|score()\|scoreTranslation\|SpaceType" \
  src/main/java/org/opensearch/knn/index/query/KNNScorer.java \
  src/main/java/org/opensearch/knn/index/SpaceType.java | head

Record in the log (Hop 3a): doANNSearch → cache load → JNIService.queryIndex → faiss → KNNScorer. Evidence: _plugins/_knn/stats hit_count/miss_count/graph_memory_usage change after the query — proof the native graph was loaded and searched off-heap.

curl -s 'localhost:9200/_plugins/_knn/stats?pretty' | grep -E 'hit_count|miss_count|graph_memory|graph_query'

Step 5: Hop 3b — the Lucene-engine search (no JNI)

Run the same trace against trace_lucene and watch the path stay inside the JVM. The lucene fork never touches KNNWeight/DefaultKNNWeight's native code; it executes Lucene's KnnFloatVectorQuery.

# Profile the lucene index and compare the query class name to the faiss one:
curl -s -XPOST 'localhost:9200/trace_lucene/_search?profile=true&pretty' \
  -H 'Content-Type: application/json' -d '{
  "size": 2, "query": { "knn": { "v": { "vector": [1.1,0.9,1.0], "k": 2 } } }
}' | grep -A2 '"query"' | head -20

# The k-NN wrappers over Lucene's vector queries:
grep -rn "extends KnnFloatVectorQuery\|extends KnnByteVectorQuery\|class OSKnnFloatVectorQuery\|class LuceneEngineKnnVectorQuery" \
  src/main/java/org/opensearch/knn/index/query/lucenelib/ \
  src/main/java/org/opensearch/knn/index/query/lucene/ | head

Record in the log (Hop 3b): the lucene query class, and the fact that _plugins/_knn/stats graph_memory_usage does not grow for a lucene-engine query (its vectors live on the JVM heap / mmap'd Lucene segment files, not in native memory).

Warning: This is the discriminating experiment. If you query the lucene index and see faiss native-memory stats move, you have mixed up your indices. The lucene engine's whole reason to exist is "no native code" — and the stats prove it.

Step 6: Hop 4 and Hop 5 — per-shard top-k and coordinator reduce

The last two hops are core mechanics, shared with every search — k-NN does not own them. Per segment you have TopDocs; Lucene's collector merges them into a per-shard top-k; the coordinating node merges per-shard results into the global top-k. This is the fan-out in search execution.

# k-NN's collector / result merge helpers (per-shard side):
grep -rn "TopDocs\|TopApproxKnnCollector\|ResultUtil\|reduce\|merge" \
  src/main/java/org/opensearch/knn/index/query/ResultUtil.java \
  src/main/java/org/opensearch/knn/index/query/TopApproxKnnCollector.java 2>/dev/null | head

Record in the log (Hops 4–5): per-shard collect, then coordinator reduce — and note that these are core, not k-NN, code. Evidence: in profile=true, the per-shard timing is under each shard's entry; the cross-shard reduce is not in the per-shard profile (it happens on the coordinator after shards return).

Step 7: Confirm with TRACE logs, then turn logging off

Read the logs you generated. The k-NN query package at TRACE prints the decisions you read in source — the engine chosen, ANN vs exact, filter cardinality, k.

# Wherever your node writes logs (./gradlew run -> build/testclusters or console):
grep -i "org.opensearch.knn.index.query" build/testclusters/*/logs/*.log 2>/dev/null | tail -40
# Or just watch the console where ./gradlew run is printing.

# IMPORTANT: reset logging so you don't drown the node in TRACE output:
curl -s -XPUT 'localhost:9200/_cluster/settings' -H 'Content-Type: application/json' -d '{
  "transient": { "logger.org.opensearch.knn.index.query": null }
}'

Stop the timer. Whatever you have in the reading log at 75 minutes is your artifact; the goal is coverage of every hop with at least one piece of evidence, not perfection.

Implementation Requirements / Deliverables

A completed reading-log artifact (~/knn-query-reading-log.md) with all seven rows filled: file:method, one-line "what happens", and an evidence cell per hop.
For Hop 1, the exact KNNQueryFactory branch that selects native vs lucene, named.
For Hop 3a, the JNI call chain named: doANNSearch → cache → JNIService.queryIndex → FaissService (native) → faiss → KNNScorer.
For Hop 3b, the Lucene query class the lucene engine produces, and proof (stats) that it does not consume native graph memory.
A profile=true response saved for both the faiss and lucene indices, with the differing query class names highlighted.
At least one TRACE log line cited per major hop where logging emits one.
Logging reset to default at the end (no lingering TRACE).

Troubleshooting

Symptom	Likely cause	Fix
`profile=true` shows an empty or generic query	the `knn` query rewrote to a different form (e.g. exact/script fallback, or matched no docs)	index more docs; confirm the field has a `method`; check the rewritten class name, not the original
TRACE logging produces nothing	logger name wrong or set on the wrong node	set `logger.org.opensearch.knn.index.query` exactly; on multi-node, it must reach the data node running the shard
faiss and lucene profiles look identical	you queried the same index twice	double-check the index name in the URL; they must be `trace_faiss` vs `trace_lucene`
`graph_memory_usage` is 0 after a faiss query	query hit the exact-search fallback, or you queried the lucene index	confirm engine is `faiss` and the segment has a built graph; `searchLeaf` may have chosen exact for a tiny/filtered set
Can't find `doToQuery` at a line number	line numbers drift between versions	`grep -n "doToQuery"` — never trust a hardcoded line number
`KNNQueryFactory` doesn't exist by that name	refactored in your version	`grep -rln "LuceneEngineKnnVectorQuery\|new KNNQuery"` to find the current fork site
Node drowns in log output	TRACE left on	reset the logger setting to `null` (Step 7)

Expected Output

# profile=true on trace_faiss (native) — the rewritten query is a KNNQuery-family class
"query": [ { "type": "KNNQuery", "description": "...", "time_in_nanos": ... } ]

# profile=true on trace_lucene — the rewritten query is a Lucene vector query
"query": [ { "type": "DocAndScoreQuery" / "KnnFloatVectorQuery"-derived, ... } ]

# _plugins/_knn/stats after the faiss query (off-heap graph loaded & searched)
"hit_count": 1, "miss_count": 1, "graph_memory_usage": 1, "graph_query_requests": 1

# _plugins/_knn/stats after the lucene query (native graph memory unchanged)
"graph_memory_usage": <same as before>   # lucene vectors are NOT in native memory

# Reading log (excerpt)
| 3a native | DefaultKNNWeight.doANNSearch | loads graph via cache, JNIService.queryIndex -> faiss | stats miss_count++ |
| 3b lucene | OSKnnFloatVectorQuery (extends Lucene KnnFloatVectorQuery) | Lucene HNSW, pure Java | graph_memory_usage flat |

Stretch Goals

Trace the filter path. Add a filter clause to the knn query and follow it into KNNWeight — find where the filter Weight is evaluated to a BitSet and how cardinality drives the pre-filter-vs-post-filter / exact-vs-ANN decision (FilterIdsSelector, canDoExactSearch). Document the new sub-hops.
Trace radial search. Issue a min_score/max_distance query instead of k and find where the builder routes it (RNNQueryFactory) and how the per-segment loop differs.
Trace rescoring. Use an on_disk/quantized field and a rescore clause; find RescoreKNNVectorQuery and where full-precision rescoring re-ranks the quantized top-k.
Watch the cache miss become a hit. Run the same faiss query twice and confirm miss_count increments once, then hit_count thereafter — proving the NativeMemoryCacheManager cached the graph.
Add your own TRACE line. In DefaultKNNWeight.doANNSearch, add a temporary log.trace(...) printing k, the segment, and the result count; rebuild, re-run, and see it appear. (Revert before committing — this is a learning probe, not a PR.)
Compare to a script-score query. Run an exact knn_score script query and trace it to the script engine instead of KNNWeight; contrast the two with the query-path chapter's approximate-vs-exact section.

Validation / Self-check

Name every hop from REST to coordinator reduce, the file:method that owns it, and which hops are core (shared with all searches) versus k-NN-specific.
Where exactly does the native-vs-lucene engine fork happen, and what Query class does each engine produce? Why does only one of them cross the JNI boundary?
In KNNWeight.searchLeaf, what decides between approximate (ANN) and exact search? Name one condition that forces exact.
Walk the native search sub-chain: from doANNSearch to faiss and back. What loads the graph, what makes the JNI call, and what turns a distance into a Lucene score?
You query the lucene index and graph_memory_usage grows. What does that tell you went wrong, and why is it impossible if you really queried a lucene-engine field?
Which two runtime signals corroborate your static read, and what does each one tell you that the other can't?
The coordinator reduce does not appear in the per-shard profile output. Why — where does it happen, and on which node?

When your reading log covers all seven hops with evidence, and you can explain the native/lucene fork from memory, you understand the k-NN query path. Continue to Lab K3: The knn_vector Field Type to trace the index path that produced the graphs you just searched, and re-read the query-path chapter for the filtering, radial, and rescoring details you stretched into above.

Open-Source Engineer & Contributor