Under certain conditions, sort values for a hit come from an unrelated document

[dbevacqua]

Elasticsearch version (bin/elasticsearch --version):

6.3.0 (from docker.elastic.co/elasticsearch/elasticsearch-oss:6.3.0)

Plugins installed: []

JVM version (java -version):

openjdk version "10.0.1" 2018-04-17
OpenJDK Runtime Environment (build 10.0.1+10)
OpenJDK 64-Bit Server VM (build 10.0.1+10, mixed mode)

OS version (uname -a if on a Unix-like system):

Linux f076156ce113 4.4.0-128-generic #154-Ubuntu SMP Fri May 25 14:15:18 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

Description of the problem including expected versus actual behavior:

Under certain conditions, sort values for a hit come from an unrelated document. The specific case illustrated below involves two documents on the same shard, one of which is PUT both before and after the other without a refresh in between.

Expected behaviour: a search with multi-level nested sort targeting that document returns "missing" sort value.

Actual behaviour: a search with multi-level nested sort targeting that document returns the sort value from the other document.

We believe the problem is wider-reaching than this as we have observed the behaviour with many (or most) of our searches which use multi-level nested sorts.

Steps to reproduce:

Execute following bash script.

#!/bin/bash

function http {
  curl -Ss -H 'Content-Type: application/json' -X "$@"
  echo
}

http DELETE "localhost:9200/test"

http PUT "localhost:9200/test"  -d '{
    "mappings": {
      "test-type": {
        "dynamic": "strict",
        "properties": {
          "nested1": {
            "type": "nested",
            "properties": {
              "nested2": {
                "type": "nested",
                "properties": {
                  "nested2_keyword": {
                    "type": "keyword"
                  },
                  "sortScore": {
                    "type": "integer"
                  }
                }
              },
              "nested1_keyword": {
                "type": "keyword"
              }
            }
          },
          "key": {
            "type": "keyword"
          }
        }
      }
    },
    "settings": {
      "index": {
        "number_of_shards": "1"
      }
    }
}
'

http PUT "localhost:9200/test/test-type/1" -d '{ "key": 1 }'

http PUT "localhost:9200/test/test-type/2" -d '{
  "key": 2,
  "nested1": [      
    {
      "nested2": [
        {
          "nested2_keyword": "nested2_bar",
          "sortScore": 1234
        }
      ],
      "nested1_keyword": "nested1_foo"
    }      
 ]
}
'

# works with refresh here (but not earlier)
#http POST "localhost:9200/test/_refresh"

#works with update instead of PUT
#http POST "localhost:9200/test/test-type/1/_update" -H 'Content-Type: application/json' -d '{ "key": 1 }'

http PUT "localhost:9200/test/test-type/1" -d '{ "key": 1 }'

http POST "localhost:9200/test/_refresh"

http GET "localhost:9200/test/_search?pretty" -d '{
  "query": {
    "bool": {
      "filter": [
        {
          "term": {
              "key":  1
          }
        }
      ]
    }
  },
  "sort": [
    {
      "nested1.nested2.sortScore": {
        "order": "desc",
        "mode": "max",
          "missing" : -1,
          "nested": {
          "path": "nested1",
          "filter": {
            "term": {
              "nested1.nested1_keyword": "nested1_foo"
            }
          },
          "nested": {
            "path": "nested1.nested2",
            "filter": {
              "term": {
                "nested1.nested2.nested2_keyword": "nested2_bar"
              }
            }
          }
        }
      }
    }
  ]
}
'

The search returns something like this:

{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : 1,
    "max_score" : null,
    "hits" : [
      {
        "_index" : "test",
        "_type" : "test-type",
        "_id" : "1",
        "_score" : null,
        "_source" : {
          "key" : 1
        },
        "sort" : [
          1234
        ]
      }
    ]
  }
}

the sort value of 1234 is defined in doc 2, not doc 1.

Provide logs (if relevant):

[elasticmachine]

Pinging @elastic/es-search-aggs

[luciansabo]

I can confirm this happening on 6.2 and 6.3. If you reindex all items that need to be sorted soring works correctly. I think it uses some kind of cache because if you update a single document, the first non-matching document appears on the same position, shifting the items.
A possible workaround is to use function_score.

[mayya-sharipova]

@luciansabo Thank you for reporting the issue!

Unfortunately I was NOT able to reproduce your issue. I followed all the steps on 6.3: put 1st doc, put 2nd doc, put 1st doc again, refresh, search. I am always getting "sort": [-1]". Can you confirm the steps are correct?

Can you reproduce this issue on an empty index?
Have you modified any index settings (refresh_interval etc)?

[polyfractal]

Oops, I thought I had replied to this earlier but looks like I forgot to hit enter.

I managed to reproduce this locally, although it wasn't consistent. Sometimes I would get -1, sometimes 1234. It may have been timing related. It felt like executing the steps slowly would return the correct sort value. But if I ran them all in one go it returned the bad value. This wasn't super consistent though, so it may just have been coincidence.

I was able to drop a breakpoint and see it collect the incorrect nested doc's values for the sort, but I'm not too familiar with how nested sorted works so didn't make any further progress.

Not super helpful, sorry :( This was on master fwiw.

[mayya-sharipova]

thanks @polyfractal, good to know that it is reproducible and worth investigating.

[luciansabo]

@mayya-sharipova I am not the issue author, @dbevacqua is, but I can confirm a similar thing happening here. We were seeing this bug on multiple docker setups and on our staging environment, both on empty index and older indexes. For us it is very easy to reproduce.
If you don't manage to reproduce I will find the time to prepare a basic mapping and detail the steps.

We sort scores with a condition to sort only scores of a user.
This happens for us only if there are nested documents not having scores. If you make any update to a single document with a score, the first document having no scores takes his place in the sort order. This issue does not happen if you reindex all documents that are retrieved.

[dbevacqua]

The original bash script I posted, if run as-is, allows me to reproduce the issue every time.

As per my comments in the bash script, calling _refresh between second and third PUT, or using _update instead of the third PUT, gives the correct results. In addition, forcing refresh by performing all PUTs of documents with ?refresh has the same effect, i.e. no erroneous sort values. I guess it's possible that on a slower machine, the default refresh interval of 1s comes into play and means that the issue does not manifest itself on every invocation of the bash script. Setting the refresh_interval to a value greater than the default may help in reproducing the issue.

Another couple of observations I have made:

• the issue is reproducible with the first level of nesting in the sort removed, i.e. we can further simplify the conditions required to reproduce the issue
• the issue occurs when I use an equivalent script-based sort referencing doc values
• with an appropriate inner_hits specification, I can extract the correct (i.e. expected) values for the sortScore field from doc values, i.e. the doc values retrieved for inner hits are correct, whereas the doc values for sorting appear not to be

I will post scripts which demonstrate these points at the earliest opportunity

[polyfractal]

Paging @martijnvg :) Could the nested sort filter be getting confused and collecting the wrong docs or something?

[dbevacqua]

I've created a gist which uses a simpler mapping and simpler queries to illustrate the points in my previous comment:

https://gist.github.com/dbevacqua/0ea04a3ad472da8e9b2c08559df874e9

Responses from all three search requests only contain doc 1, which has nested1.nested2.sortValue of 1, but the hit has "sort" : [ 2 ]

[dbevacqua]

After some more experimenting I've discovered that the first PUT is unnecessary. Have revised the gist to reflect this.

https://gist.github.com/dbevacqua/0ea04a3ad472da8e9b2c08559df874e9

[dbevacqua]

The problem may be in the BitSet passed into MultiValueMode.select(SortedNumericDocValues, long, BitSet, DocIdSetIterator, int). It always seems to have cardinality 0, which means that prevParentDoc is always -1, so the call to childDocs.advance(...) always returns the first child doc in childDocs, regardless of whether it's related to the current parent doc.