Boolean query (should match) performance degradation after upgrading to 8.13.2 (from 8.7.1)

After upgrading from 8.7.1 to 8.13.2, some of our queries got slower.

After digging, I've identified that a simple boolean query is getting slower on 8.13.2. It seems create_weight step is taking about 5x duration as you can see in the profiles I've shared. The difference may seem tiny but it makes my production query about 5x times slower as my query has nearly a hundred of "should" clauses.

We are running ES on K8S using ECK but it can be reproducible with docker environments.

I've tested with several ES versions (w/ docker) and I believe this issue was introduced at 8.12.0.

I have opened a similar topic as Named query performance degradation after upgrading to 8.13.2 (from 8.7.1) but this is a different issue.

8.7.1

--- 1st RUN ---
{
  "took" : 36,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[_4V8ixH1R_yrjsWYEDhRwQ][test_index][0]",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 890916,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 887875,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 3041
                }
              }
            ],
            "rewrite_time" : 224292,
            "collector" : [
              {
                "name" : "SimpleTopScoreDocCollector",
                "reason" : "search_top_hits",
                "time_in_nanos" : 192418
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}
--- 2nd RUN ---
{
  "took" : 2,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[_4V8ixH1R_yrjsWYEDhRwQ][test_index][0]",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 233750,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 232583,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 1167
                }
              }
            ],
            "rewrite_time" : 4625,
            "collector" : [
              {
                "name" : "SimpleTopScoreDocCollector",
                "reason" : "search_top_hits",
                "time_in_nanos" : 2416
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}
--- 3rd RUN ---
{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[_4V8ixH1R_yrjsWYEDhRwQ][test_index][0]",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 87959,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 87042,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 917
                }
              }
            ],
            "rewrite_time" : 4917,
            "collector" : [
              {
                "name" : "SimpleTopScoreDocCollector",
                "reason" : "search_top_hits",
                "time_in_nanos" : 1625
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}

8.13.2

--- 1st RUN ---
{
  "took" : 42,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[4hvhIe0hSMSfEx6hxP5a6A][test_index][0]",
        "node_id" : "4hvhIe0hSMSfEx6hxP5a6A",
        "shard_id" : 0,
        "index" : "test_index",
        "cluster" : "(local)",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 2038668,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 2033959,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 4709
                }
              }
            ],
            "rewrite_time" : 256125,
            "collector" : [
              {
                "name" : "QueryPhaseCollector",
                "reason" : "search_query_phase",
                "time_in_nanos" : 398167,
                "children" : [
                  {
                    "name" : "SimpleTopScoreDocCollector",
                    "reason" : "search_top_hits",
                    "time_in_nanos" : 253542
                  }
                ]
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}
--- 2nd RUN ---
{
  "took" : 3,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[4hvhIe0hSMSfEx6hxP5a6A][test_index][0]",
        "node_id" : "4hvhIe0hSMSfEx6hxP5a6A",
        "shard_id" : 0,
        "index" : "test_index",
        "cluster" : "(local)",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 537083,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 535791,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 1292
                }
              }
            ],
            "rewrite_time" : 5917,
            "collector" : [
              {
                "name" : "QueryPhaseCollector",
                "reason" : "search_query_phase",
                "time_in_nanos" : 7082,
                "children" : [
                  {
                    "name" : "SimpleTopScoreDocCollector",
                    "reason" : "search_top_hits",
                    "time_in_nanos" : 2667
                  }
                ]
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}
--- 3rd RUN ---
{
  "took" : 2,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 0,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "profile" : {
    "shards" : [
      {
        "id" : "[4hvhIe0hSMSfEx6hxP5a6A][test_index][0]",
        "node_id" : "4hvhIe0hSMSfEx6hxP5a6A",
        "shard_id" : 0,
        "index" : "test_index",
        "cluster" : "(local)",
        "searches" : [
          {
            "query" : [
              {
                "type" : "TermQuery",
                "description" : "test_text:ewobzemoud",
                "time_in_nanos" : 469417,
                "breakdown" : {
                  "set_min_competitive_score_count" : 0,
                  "match_count" : 0,
                  "shallow_advance_count" : 0,
                  "set_min_competitive_score" : 0,
                  "next_doc" : 0,
                  "match" : 0,
                  "next_doc_count" : 0,
                  "score_count" : 0,
                  "compute_max_score_count" : 0,
                  "compute_max_score" : 0,
                  "advance" : 0,
                  "advance_count" : 0,
                  "count_weight_count" : 0,
                  "score" : 0,
                  "build_scorer_count" : 2,
                  "create_weight" : 468292,
                  "shallow_advance" : 0,
                  "count_weight" : 0,
                  "create_weight_count" : 1,
                  "build_scorer" : 1125
                }
              }
            ],
            "rewrite_time" : 5167,
            "collector" : [
              {
                "name" : "QueryPhaseCollector",
                "reason" : "search_query_phase",
                "time_in_nanos" : 6625,
                "children" : [
                  {
                    "name" : "SimpleTopScoreDocCollector",
                    "reason" : "search_top_hits",
                    "time_in_nanos" : 2417
                  }
                ]
              }
            ]
          }
        ],
        "aggregations" : [ ]
      }
    ]
  }
}

Step to reproduce

Index template (index_template.json)

% cat index_template.json 
{
  "index_patterns": ["test*"],
  "mappings": {
    "properties": {
      "test_text": {
          "type": "text"
      }
    }
  }
}

Query (query.json)

% cat query.json 
{"profile": true, "query": {"bool": {"should": [{"match": {"test_text": "ewobzemoud"}}]}}}

Test data (bulk_requests.json)
https://raw.githubusercontent.com/shimpeko/es_named_query_perf/main/bulk_requests.json
note: The file is prepared for different issue but can also be used for this issue.

Commands (commands.sh)

% cat commands.sh 
#!/bin/bash

curl -X GET http://localhost:19200/_cluster/health?wait_for_status=green&timeout=30s
curl -X DELETE http://localhost:19200/_template/template_1
curl -X PUT http://localhost:19200/_template/template_1 -H 'Content-Type: application/json' --data "@index_template.json"
curl -X DELETE http://localhost:19200/test_index
curl -X PUT http://localhost:19200/test_index
curl -s -X POST http://localhost:19200/test_index/_bulk/?refresh=wait_for -H 'Content-Type: application/json' --data-binary "@bulk_requests.json" > /dev/null
curl -X GET http://localhost:19200/test_index/_mappings
echo ""
echo ""
echo "--- 1st RUN ---"
curl -X POST http://localhost:19200/test_index/_search?pretty=true -H 'Content-Type: application/json' --data "@query.json"
echo "--- 2nd RUN ---"
curl -X POST http://localhost:19200/test_index/_search?pretty=true -H 'Content-Type: application/json' --data "@query.json"
echo "--- 3rd RUN ---"
curl -X POST http://localhost:19200/test_index/_search?pretty=true -H 'Content-Type: application/json' --data "@query.json"

For 8.7.2

% cat docker-compose-8-7.yaml 
services:
  elastic:
    image: docker.elastic.co/elasticsearch/elasticsearch:8.7.1
    environment:
    - node.name=myes
    - bootstrap.memory_lock=true
    - cluster.initial_master_nodes=myes
    - cluster.name=myes
    - ES_JAVA_OPTS=-Xms1g -Xmx1g -Dlog4j2.formatMsgNoLookups=true
    - xpack.security.enabled=false
    - action.destructive_requires_name=false
    ulimits:
      memlock:
        soft: -1
        hard: -1
      nofile:
        soft: 65536
        hard: 65536
    ports:
    - "19200:9200"
% docker compose -f docker-compose-8-7.yaml up -d
% ./commands.sh

For 8.13.2

% cat docker-compose-8-13.yaml 
services:
  elastic:
    image: docker.elastic.co/elasticsearch/elasticsearch:8.13.2
    environment:
    - node.name=myes
    - bootstrap.memory_lock=true
    - cluster.initial_master_nodes=myes
    - cluster.name=myes
    - ES_JAVA_OPTS=-Xms1g -Xmx1g -Dlog4j2.formatMsgNoLookups=true
    - xpack.security.enabled=false
    - action.destructive_requires_name=false
    ulimits:
      memlock:
        soft: -1
        hard: -1
      nofile:
        soft: 65536
        hard: 65536
    ports:
    - "19200:9200"
% docker compose -f docker-compose-8-13.yaml up
% ./commands.sh

Also confirmed this is not fixed with the latest 8.13.4.

You can see a significant different in the "took" value with a larger query like query.json · GitHub.

@dadoonet Shall I also open a GitHub issue for this one? I'm not opening an issue directly only because the repository says that I should report potential bugs first to this forum.

Opened Boolean query performance regression after upgrading to 8.13.2 (from 8.7.1) · Issue #108659 · elastic/elasticsearch · GitHub

1 Like