Advance binary doc runtime error

[iandanforth-alation]

I am hitting this error.

Traceback (most recent call last):
...
  File "/opt/alation/env/lib/python3.6/site-packages/elasticsearch/connection/base.py", line 182, in _raise_error
    status_code, error_message, additional_info
elasticsearch.exceptions.TransportError: TransportError(500, 'search_phase_execution_exception', 'Could not advance binary doc values reader
 from doc ID [32] to doc ID [33]. It is possible that the document [33] does not have a 
vector. Consider trying with an `exists` query: "exists": { "field": "encoding_msmarco-
MiniLM-L-6-v3" }')

I am having trouble debugging this because I don't understand what a 'binary doc values reader' is and when/why it needs to be advanced.

Any pointers would be greatly appreciated!

[alexklibisz]

Can you double check that all documents in the index have a vector field populated? From the error message:

'Could not advance binary doc values reader
 from doc ID [32] to doc ID [33]. It is possible that the document [33] does not have a 
vector. Consider trying with an `exists` query: "exists": { "field": "encoding_msmarco-
MiniLM-L-6-v3" }'

[iandanforth-alation]

Sorry the reason I ask for context is that the deployed example is treated as pseudo-production and is very difficult to debug directly. I'm trying to reproduce the issue outside of the environment it was thrown.

[iandanforth-alation]

If it helps I found this in the non-error logs, on a more recent error.

current.AbstractRunnable.run(AbstractRunnable.java:26) ~[elasticsearch-7.16.2.jar:7.16.2]
--
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.action.ActionRunnable$2.doRun(ActionRunnable.java:62) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.action.ActionRunnable.lambda$supply$0(ActionRunnable.java:47) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.SearchService.lambda$executeQueryPhase$2(SearchService.java:483) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:622) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:458) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:98) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.query.QueryPhase.executeInternal(QueryPhase.java:212) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.query.QueryPhase.searchWithCollector(QueryPhase.java:255) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:443) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.internal.ContextIndexSearcher.search(ContextIndexSearcher.java:167) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.internal.ContextIndexSearcher.searchLeaf(ContextIndexSearcher.java:194) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.search.internal.CancellableBulkScorer.score(CancellableBulkScorer.java:45) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:245) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.Weight$DefaultBulkScorer.scoreRange(Weight.java:265) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.ConjunctionDISI$ConjunctionTwoPhaseIterator.matches(ConjunctionDISI.java:381) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.common.lucene.search.function.MinScoreScorer$1.matches(MinScoreScorer.java:75) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.elasticsearch.common.lucene.search.function.FunctionScoreQuery$FunctionFactorScorer.score(FunctionScoreQuery.java:414) ~[elasticsearch-7.16.2.jar:7.16.2]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.FilterScorer.score(FilterScorer.java:59) ~[lucene-core-8.10.1.jar:8.10.1 2f24e6a49d48a032df1f12e146612f59141727a9 - mayyasharipova - 2021-10-12 15:13:05]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at org.apache.lucene.search.MatchHashesAndScoreQuery$1$2.score(MatchHashesAndScoreQuery.java:189) ~[?:?]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at com.klibisz.elastiknn.query.HashingQuery.$anonfun$toLuceneQuery$2(HashingQuery.scala:25) ~[?:?]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | at com.klibisz.elastiknn.storage.StoredVecReader.apply(StoredVecReader.scala:19) ~[?:?]
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | Caused by: com.klibisz.elastiknn.ElastiknnException$ElastiknnRuntimeException: Could not advance binary doc values reader from doc ID [11] to doc ID [17]. It is possible that the document [17] does not have a vector. Consider trying with an `exists` query: "exists": { "field": "encoding_msmarco-MiniLM-L-6-v3" }
  | Apr 21 17:13:10.703 | i-063ca5123e16f9a51 | alationfc | ... 22 more

Conceptually I don't understand the error. In what contexts could Elastiknn be interacting with a document that doesn't have a vector? How could a document make it into the Elastiknn index without one?

[alexklibisz]

"DocValues" are a way to store some data associated with a specific document. DocValues don't get indexed, so you save on storage and memory and they also have some other benefits for performance. See this document for more: https://solr.apache.org/guide/6_6/docvalues.html

A binary doc value is just a doc value that happens to be a byte array. Elastiknn vectors are encoded to byte arrays and stored as binary doc values.

So the BinaryDocValues is a class that lets us read the binary doc value for a specific document, identified by an ID. I refer to it as a "binary doc values reader" in that error message, but I believe the actual class is called BinaryDocValues.

The last error you posted says that the BinaryDocValues instance was previously at document 11, tried to traverse to document 17, but could not find a binary doc value for document 17.

How can this happen? The only case I know when this happens is this:

1. Populate an index that has some documents with a vector and other documents without a vector.
2. Run some variation of an exact elastiknn query on this index.
3. The exact query tries to look at all documents and crashes on one of the documents that has no vector.

So, a couple things to do next:

1. Check if all of the documents in this index have an elastiknn vector
2. Post a reproducible example with some data and queries that represent your situation.

If it turns out that they all have vectors, then I'll really need a reproducible example to help more.