Percolator with groovy script fails when doc_values are enabled

[WellingR]

Tested on Elasticsearch 1.7.1.

Prepare the mapping and percolator as follows:

curl -XPUT localhost:9200/test -d '{
  "mappings" : {
    "test" : {
      "properties" : {
        "name" : {
          "type" : "string",
          "index" : "not_analyzed",
          "doc_values": true
        }
      }
    }
  }
}'
curl -XPUT localhost:9200/test/.percolator/1 -d '{
  "type": "test",
  "query": {
    "constant_score": {
      "filter": {
        "script": {
          "script": "doc[\"name\"].value.contains(\"a\")",
          "lang": "groovy"
        }
      }
    }
  }
}'

This script tests for a match, it keeps looping silently as long as the expected result arrives. When an unexpected result arrives it's printed and the loop terminates:

while ! curl -s localhost:9200/test/test/_percolate -d '{ "doc": { "name": "a" } }' | grep -v '"failed":0},"total":1'; do :; done

Unfortunately the script fails instantly.

{"took":5,"_shards":{"total":5,"successful":4,"failed":1,"failures":[{"index":"test","shard":2,"status":400,"reason":"BroadcastShardOperationFailedException[[test][2] ]; nested: PercolateException[failed to percolate]; nested: PercolateException[failed to execute]; nested: GroovyScriptExecutionException[NullPointerException[Cannot invoke method contains() on null object]]; "}]},"total":0,"matches":[]}

Elasticsearch logs the following stacktrace

[2015-09-01 13:51:02,378][DEBUG][action.percolate         ] [esnode-r] [test][2], node[rbfvveU3R3GjVtXyTzQp9g], [P], s[STARTED]: failed to execute [org.elasticsearch.action.percolate.PercolateRequest@d53bdf0]
org.elasticsearch.percolator.PercolateException: failed to percolate
    at org.elasticsearch.action.percolate.TransportPercolateAction.shardOperation(TransportPercolateAction.java:195)
    at org.elasticsearch.action.percolate.TransportPercolateAction.shardOperation(TransportPercolateAction.java:56)
    at org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$AsyncBroadcastAction$1.run(TransportBroadcastOperationAction.java:170)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.elasticsearch.percolator.PercolateException: failed to execute
    at org.elasticsearch.percolator.PercolatorService$4.doPercolate(PercolatorService.java:564)
    at org.elasticsearch.percolator.PercolatorService.percolate(PercolatorService.java:242)
    at org.elasticsearch.action.percolate.TransportPercolateAction.shardOperation(TransportPercolateAction.java:192)
    ... 5 more
Caused by: org.elasticsearch.script.groovy.GroovyScriptExecutionException: NullPointerException[Cannot invoke method contains() on null object]
    at org.elasticsearch.script.groovy.GroovyScriptEngineService$GroovyScript.run(GroovyScriptEngineService.java:274)
    at org.elasticsearch.index.query.ScriptFilterParser$ScriptFilter$ScriptDocSet.matchDoc(ScriptFilterParser.java:187)
    at org.elasticsearch.common.lucene.docset.MatchDocIdSet$NoAcceptDocsIterator.nextDoc(MatchDocIdSet.java:96)
    at org.apache.lucene.search.ConstantScoreQuery$ConstantScorer.nextDoc(ConstantScoreQuery.java:257)
    at org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:192)
    at org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:163)
    at org.apache.lucene.search.BulkScorer.score(BulkScorer.java:35)
    at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:621)
    at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:309)
    at org.elasticsearch.common.lucene.Lucene.countWithEarlyTermination(Lucene.java:320)
    at org.elasticsearch.common.lucene.Lucene.countWithEarlyTermination(Lucene.java:308)
    at org.elasticsearch.common.lucene.Lucene.exists(Lucene.java:299)
    at org.elasticsearch.percolator.PercolatorService$4.doPercolate(PercolatorService.java:560)
    ... 7 more

This issue does not occur when the line "doc_values": true is not included in the mapping (it defaults to false in elasticsearch 1.7.1).
What perhaps is worse, if that the wrong result (no result) is returned when the percolator script is changed to "doc[\"name\"].value == \"a\"".

I discovered this issue because we use the workaround mentioned in #8879 to avoid percolator concurrency issues. Since elasticsearch uses doc_values by default, we were investigating what the performance inpact is of using docvalues, however we discovered this unexpected problem.

[clintongormley]

In master this fails with:

"failed to run inline script [doc[\"name\"].value.contains(\"a\")] using lang [groovy]: IllegalStateException[unexpected docvalues type NONE for field 'name' (expected one of [SORTED, SORTED_SET]). Use UninvertingReader or index with docvalues.]"

[rjernst]

IIRC, doc values is not supported in MemoryIndex.

[s1monw]

it's not supported though

[clintongormley]

Could one possibility be to ignore the doc values setting when creating the in-memory index?

[jpountz]

I think this is what already happens today. Then the issue arises at search time because fielddata tries to load through doc values (because the mappings say this is how it should get it) but they are missing so doc[\"name\"].value returns null instead of the document value, hence the NPE.

[WellingR]

I have seen a similar issue when I use a geo_point with both geohash_prefix and doc_values enabled. A geo_distance filter never seems to match when doc_values are enabled. Does this have the same cause or is this a separate issue?

[martijnvg]

From 5.0 the memory index will support doc values, which will fix the issue reported here.