Unexpected behaviour with script query (script executed twice)

[luis1 (Luis)]

Hi, all. I found some unexpected behaviour with script query (script is executing twice in a simple query). The steps to reproduce the issue:

My elastic search version: 2.4.6
My elasticsearch.yml:

script.indexed: true

Steps:

1. I have one simple document, doc1.json:

{
	"id": "1",
	"tags": "t1"
}

2. Insert doc1 in Elastic:

http PUT localhost:9200/default/type1/1 @doc1.json

3. I have one simple groovy script, script1.json (just returns the score and print it):

{
     "script": "println('Score is ' + _score * 1.0 + ' for document ' + doc['id'] + ' at ' + DateTime.now().getMillis()); return _score;"
}

4. Register script1:

http POST 'localhost:9200/_scripts/groovy/script1' @script1.json

5. Execute this query_with_script.json:

{
   "query":{
      "function_score":{
         "query":{
            "bool":{
               "must":{
                  "match":{
                     "tags":{
                        "query":"t1",
                        "type":"boolean"
                     }
                  }
               }
            }
         },
         "functions":[
            {
               "script_score":{
                  "script":{
                     "id":"script1",
                     "lang":"groovy"
                  }
               }
            }
         ],
         "boost_mode":"replace"
      }
   },
   "explain" : true
}

http GET 'localhost:9200/default/type1/_search' @query_with_script.json

6. Why in Elastic search logs I see that the script is executed in two different times?

Score is 0.19178301095962524 for document [1] at 1516586818596
Score is 0.19178301095962524 for document [1] at 1516586818606

Thanks a lot!

[dadoonet (David Pilato)]

May be you have 2 shards?

[luis1 (Luis)]

Hi! I have 5 yards, but only one document. Moreover, I created an index with only 1 yard, but the issue still remains. Issue can be easily reproduced in a couple of minutes following the steps. Thanks!

[dadoonet (David Pilato)]

As far as I remember we fixed once such an issue but I can't recall where it has been fixed.

Any chance you could reproduce this on 5.6 or better on 6.1 with a painless script instead?

[luis1 (Luis)]

Unfortunately, we are at production and we can't migrate to 5.x because of lack of compatibility between Elastic 5.x and the well known artifact spring-boot-starter-data-elasticsearch

[luis1 (Luis)]

Same behaviour in Elastic 5.6.0, why script is being executed twice? Is it a bug?

[dadoonet (David Pilato)]

What happen if you remove "explain" : true?

[luis1 (Luis)]

It was that. Thanks!