Fuzzy match very slow on indices with shingle filter

[jeantil]

Elasticsearch version:
5.2.2 (I reproduced this issue on the 5.2.2 docker image provided by elastic.co)

Plugins installed: [x-pack:5.2.2]
(is installed by default in the docker image)
JVM version:

                "version": "1.8.0_92-internal",
                "vm_name": "OpenJDK 64-Bit Server VM",
                "vm_vendor": "Oracle Corporation",
                "vm_version": "25.92-b14"

OS version:
the os of the docker image is a linux, it runs on docker4mac 17.03.0-ce-mac2 (15657) on mac osX sierra

Description of the problem including expected versus actual behavior:
Running the following request on a very small index (see reproduction steps) is consistently very slow:

GET season/season/_search
{
  "query" : {
    "bool" : {
      "must" : [
        {
          "match" : {
            "name.classic" : {
              "query" : "RENAULT Talisman Talisman Estate 1.6 dCi 130 225/55 R17 101W winter",
              "operator" : "OR",
              "fuzziness" : "AUTO",
              "prefix_length" : 0,
              "max_expansions" : 50,
              "fuzzy_transpositions" : true,
              "lenient" : false,
              "zero_terms_query" : "NONE",
              "boost" : 1.0
            }
          }
        }
      ],
      "disable_coord" : false,
      "adjust_pure_negative" : true,
      "boost" : 1.0
    }
  }
}

the previous query returns in over 3 seconds :

 "took": 4360,

when disabling the fuzzyness the query runs orders of magnitude faster

  "took": 87,

disabling shingling in the query analysis also runs orders of magnitude faster

  "took": 11,

Steps to reproduce:

DELETE season
PUT season
{
  "settings": {
    "index": {
      "analysis": {
        "filter": {
          "search_shingler": {
            "max_shingle_size": "3",
            "min_shingle_size": "2",
            "token_separator": " ",
            "output_unigrams": "true",
            "filler_token": "_",
            "output_unigrams_if_no_shingles": "false",
            "type": "shingle"
          }
        },
        "analyzer": {
          "seasons-searchAnalyzer": {
            "filter": [
              "asciifolding",
              "lowercase",
              "search_shingler"
            ],
            "type": "custom",
            "tokenizer": "whitespace"
          },
          "seasons-indexAnalyzer": {
            "filter": [
              "asciifolding",
              "lowercase"
            ],
            "type": "custom",
            "tokenizer": "keyword"
          }
        }
      }
    }
  }
}

PUT season/_mapping/season
{
 "properties": {
   "name": {
     "type": "text",
     "fields": {
       "classic": {
         "type": "text",
         "analyzer": "seasons-indexAnalyzer",
         "search_analyzer": "seasons-searchAnalyzer"
       },
       "raw": {
         "type": "keyword"
       }
     }
   },
   "value": {
     "type": "keyword"
   }
 }   
}
POST season/season
{ "name": "winter", "value": "Winter"}
POST season/season
{ "name": "winteur", "value": "Winter"}
POST season/season  
{ "name": "summer", "value": "Summer"}
POST season/season  
{ "name": "all seasons", "value": "AllSeasons"}
POST season/season  
{ "name": "nordic", "value": "Nordic" }

Provide logs (if relevant):
I couldn't find anything relevant in the logs (I only get deleting index, creating index, adding mapping, etc... )

comparison with previous versions

I tried running the exact same scenario on our previous configuration (es 1.7) the query with both fuzzy and shingling ran in about 150ms. we never tried intermediate versions as our upgrade path was blocked by the removal of FLT until #9103 got merged.

[jeantil]

Sorry I closed the issue in the wrong tab this is still an issue for us.

[jeantil]

I have new information regarding this issue. After our production cluster crashed twice despite having disabled shingling on the fields used in fuzzy searches we discovered that shingling alone was enough to trigger gc and out of memory errors even on very small indices.

On the provided index which contains all of 5 documents with 2 small fields each, the following query will crash a 1g heap elasticsearch instance on 5.2.2 and 5.3.0 (using the elasticsearch provided docker image as is).

GET season/season/_search
{
  "query" : {
    "bool" : {
      "must" : [
        {
          "match" : {
            "name.classic" : {
              "query" : "winter winter winter winter winter winter winter winter winter winter winter winter winter winter winter winter winter winter winter",
              "operator" : "OR",
              "fuzziness" : "AUTO",
              "prefix_length" : 0,
              "max_expansions" : 50,
              "fuzzy_transpositions" : true,
              "lenient" : false,
              "zero_terms_query" : "NONE",
              "boost" : 1.0
            }
          }
        }
      ],
      "disable_coord" : false,
      "adjust_pure_negative" : true,
      "boost" : 1.0
    }
  }
}

here is my docker compose file in case it helps:

version: '2'
services:
  elasticsearch:
    image: docker.elastic.co/elasticsearch/elasticsearch:5.3.0
    environment:
      - xpack.security.enabled=false
      - xpack.monitoring.enabled=false
      - cluster.name=rzv2
      - bootstrap.memory_lock=true
      - "ES_JAVA_OPTS=-Xms1g -Xmx1g -Dcom.sun.management.jmxremote.port=8000 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.rmi.port=8000 -Djava.rmi.server.hostname=localhost -Dcom.sun.management.jmxremote.local.only=false"
    ulimits:
      memlock:
        soft: -1
        hard: -1
      nofile:
        soft: 65536
        hard: 65536
    mem_limit: 3g
    expose:
      - "9200"
      - "9300"
      - "8000"
    ports:
      - "9301:9300"
      - "9201:9200"
      - "8000:8000"
    volumes:
      - ./es:/usr/share/elasticsearch/config
      - esdata:/usr/share/elasticsearch/data
  kibana:
    image: docker.elastic.co/kibana/kibana:5.3.0
    links:
       - elasticsearch:elasticsearch
    ports:
      - "5601:5601"
volumes: 
  esdata:
    driver: local

my elasticsearch.yml in config

network.host: 0.0.0.0

# this value is required because we set "network.host"
# be sure to modify it appropriately for a production cluster deployment
discovery.zen.minimum_master_nodes: 1
cluster.name: foo
thread_pool:
  bulk:
    queue_size: 100
http.cors.enabled: true
http.cors.allow-origin: /.*/
http.detailed_errors.enabled: true

I tried successively adding terms and ES displayed 3 behaviours:

• 0-12 terms => works fine
• 13-18 terms => query fails with too_many_clauses slow downs can be seen after 16th term is added.
• 19+ terms => run away gs process and/or out of memory errors

It looks like computing the clauses breaks down and the initial issue wasn't directly related to fuzzyness.

elasticsearch_1  | [2017-04-10T10:01:24,221][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][276] overhead, spent [1.9s] collecting in the last [2.1s]
elasticsearch_1  | [2017-04-10T10:01:26,476][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][277] overhead, spent [2.2s] collecting in the last [2.2s]
elasticsearch_1  | [2017-04-10T10:01:27,732][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][278] overhead, spent [1.2s] collecting in the last [1.2s]
elasticsearch_1  | [2017-04-10T10:01:31,572][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][279] overhead, spent [3.7s] collecting in the last [3.8s]
elasticsearch_1  | [2017-04-10T10:01:32,953][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][280] overhead, spent [1.3s] collecting in the last [1.3s]
elasticsearch_1  | [2017-04-10T10:01:36,276][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][281] overhead, spent [3.3s] collecting in the last [3.3s]
elasticsearch_1  | [2017-04-10T10:01:38,440][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][282] overhead, spent [2.1s] collecting in the last [2.1s]
elasticsearch_1  | [2017-04-10T10:02:10,347][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][283] overhead, spent [6.9s] collecting in the last [5.4s]
elasticsearch_1  | [2017-04-10T10:02:11,793][ERROR][o.e.b.ElasticsearchUncaughtExceptionHandler] [] fatal error in thread [elasticsearch[RyddBEl][search][T#4]], exiting
elasticsearch_1  | java.lang.OutOfMemoryError: GC overhead limit exceeded
elasticsearch_1  | 	at org.apache.lucene.util.BytesRef.deepCopyOf(BytesRef.java:206) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.analysis.tokenattributes.BytesTermAttributeImpl.copyTo(BytesTermAttributeImpl.java:53) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.AttributeSource.restoreState(AttributeSource.java:325) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.analysis.CachingTokenFilter.incrementToken(CachingTokenFilter.java:79) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.analyzeMultiBoolean(QueryBuilder.java:374) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.createFieldQuery(QueryBuilder.java:315) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.analyzeGraph(QueryBuilder.java:461) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.createFieldQuery(QueryBuilder.java:298) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.createFieldQuery(QueryBuilder.java:235) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.apache.lucene.util.QueryBuilder.createBooleanQuery(QueryBuilder.java:91) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
elasticsearch_1  | 	at org.elasticsearch.index.search.MatchQuery.parse(MatchQuery.java:257) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.MatchQueryBuilder.doToQuery(MatchQueryBuilder.java:466) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.AbstractQueryBuilder.toQuery(AbstractQueryBuilder.java:96) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.BoolQueryBuilder.addBooleanClauses(BoolQueryBuilder.java:442) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.BoolQueryBuilder.doToQuery(BoolQueryBuilder.java:416) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.AbstractQueryBuilder.toQuery(AbstractQueryBuilder.java:96) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.QueryShardContext.lambda$toQuery$1(QueryShardContext.java:313) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.QueryShardContext$$Lambda$1724/1557619835.apply(Unknown Source) ~[?:?]
elasticsearch_1  | 	at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:325) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:312) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.search.SearchService.parseSource(SearchService.java:599) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.search.SearchService.createContext(SearchService.java:468) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:444) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:252) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:331) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:328) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:618) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:613) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-5.3.0.jar:5.3.0]
elasticsearch_1  | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_92-internal]
elasticsearch_1  | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_92-internal]
elasticsearch_1  | [2017-04-10T10:02:11,827][WARN ][o.e.m.j.JvmGcMonitorService] [RyddBEl] [gc][284] overhead, spent [26.3s] collecting in the last [27.9s]

[jeantil]

sounds like this could be linked to #23918
The second use case clearly seems related. What I am unsure about is if the initial issue (fuzzy vs non fuzzy for shingles) is a consequence of #23918 or if it's yet a different issue.

[clintongormley]

@jeantil this does indeed look like a duplicate. Basically, it's bad practice to mix variable length shingles (or ngrams) in a single field. You have shingles of length 1, 2, and 3! With the new graph analysis of shingles in Lucene 6.x, this results in an explosion of possible combinations, hence the OOM.

The fix in #23918 is to disable graph analysis in the presence of mixed length shingles, but the better answer is to use only a single shingle length in a single field.

[jeantil]

Note that in my case the shingling is applied to the query string not to the fields (though the resulting shingles are still matched against multiple fields) ...
Is it still bad practice to mix variable length shingles in that case ?

This was initially setup as a way to boost partial exact matches ( a sub string of the query is exactly the content of a field) over fuzzy matches since fuzzy and idf sometimes end up boosting fuzzy matches over exact ones.
we use the shingling to generate all the substrings and apply them to a keyword indexed field.

[clintongormley]

Is it still bad practice to mix variable length shingles in that case ?

yes. fuzzy just makes it worse

fuzzy and idf sometimes end up boosting fuzzy matches over exact ones.

that should no longer be the case.

we use the shingling to generate all the substrings and apply them to a keyword indexed field.

to a keyword indexed field? why would you do that?

[jeantil]

fuzzy and idf sometimes end up boosting fuzzy matches over exact ones.
that should no longer be the case.

well we are still having issues with #22745 which is not a bug but is still an issue for our relevancy.

to a keyword indexed field? why would you do that?

It is an attempt to be able to boost exact submatches. it is fairly hard to isolate a precise case, all the more so since I don't have our non-regression testsuite and dataset at hand.

consider the following documents (completely contrived I don't have my usual dataset on hand)

{
"brand": "dell", 
"range":"laptop", 
"product":"inspiron 7000", 
"size":"15",
"phrase":"dell inspiron inspiron 7000 15"
}
{
"brand": "dell", 
"range":"laptop", 
"product":"inspiron 7000", 
"size":"13",
"phrase":"dell inspiron inspiron 7000 13"
}
{
"brand": "dell", 
"range":"laptop", 
"product":"inspiron 7000", 
"size":"11",
"phrase":"dell inspiron inspiron 7000  11"
}
{
"brand": "foo", 
"range":"insparon", 
"product":"insparon 7000", 
"size":"insparon 7000",
"phrase":"foo inparon insparon 7000 insparon 13 7000"
}

and the query for "new york inspiron 7000"

Our fields have 2 subfields : .search and .keyword

• .search is indexed with a whitespace tokenizer, ascii folding, a charfilter to map (,+ and * to words to avoid side effects, a worddelimiter to split on case change, alpha/num transitions all this goes through a synonyms filter and finally all is lowercased
• .keywords has keyword tokenizer then asciifolding, signmapping, lowercase then a synonym filter which also uses keywork tokenization.

we use a query like this

bool:
  must:
    multi_match fuzzy most fields accross all fields (.search and .keywords fields + phrase
  should:
    phrase match on phrase 
    multi_match cross field on all .search and .keywords fields + phrase 

if we remove the keyword fields some queries end up hitting #22745 and prioritizing fuzzy matches over exact matches.

• Using the default analyzer the query "washington inspiron 7000" =>[washington, inspiron, 7000] doesn't match on the product keyword
• using a keyword analyzer "washington inspiron 7000" =>["washington inspiron 7000"] which of course doesn't match on the product keyword.

With this query the phrase match doesn't match either which leaves the .search on cross fields and the fuzzy queries. We have enough queries where this leads to fuzzy matches ending up ranked above exact matches that we tried to boost exact matches through shingling.

• with witespace+shingling(min 2 max 5 + unigrams) as query analyzer for keyword fields +phrase we get
  "new york inspiron 7000" => ["new", "new york", "new york inspiron", new york inspiron 7000", "york", "york inspiron","york inspiron 7000", "inspiron", "inspiron 7000","7000"]
  which does get a match on the product keywords (thanks to "inspiron 7000") in addition to getting a match on the phrase field ("inspiron", "inspiron 7000", "7000") too.
  this and a couple well placed boosts was enough to greatly improve our relevancy.

I guess we will be good for digging into the queries again and see if we can come up with an alternate strategy to drop shingling entirely.

[andyb-elastic]

Since it looks like some changes have been made that mitigate this issue (#23918 disables graph analysis for mixed-length shingles, and #27211 adds soft limits for shingle sizes) I'm going to close. Additional feedback is always welcome