Simple Query (1 cardinality, 19,000 docs) takes ~100k ms to complete

Hi All,

Elasticsearch: 7.13.2

I am wondering if anyone could help provide some input into an issue that I'm seeing.

I am using a fairly simple query:

Query is executed against filebeat-*

"query": {
    "bool": {
      "must": [],
      "filter": [
        {
          "bool": {
            "should": [
              {
                "bool": {
                  "should": [
                    {
                      "query_string": {
                        "fields": [
                          "url.path"
                        ],
                        "query": "\\/_apps\\/<app_name>*"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              },
              {
                "bool": {
                  "should": [
                    {
                      "match_phrase": {
                        "url.original.text": "/_apps/<app_name>"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              }
            ],
            "minimum_should_match": 1
          }
        },
        {
          "bool": {
            "should": [
              {
                "bool": {
                  "should": [
                    {
                      "query_string": {
                        "fields": [
                          "url.path"
                        ],
                        "query": "\\/_apps\\/<app_name>*"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              },
              {
                "bool": {
                  "should": [
                    {
                      "match_phrase": {
                        "url.original.text": "/_apps/<app_name>"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              }
            ],
            "minimum_should_match": 1
          }
        },
        {
          "bool": {
            "minimum_should_match": 1,
            "should": [
              {
                "match_phrase": {
                  "host.name": "<host_1>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_2>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_3>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_4>"
                }
              }
            ]
          }
        },
        {
          "match_phrase": {
            "event.module": "iis"
          }
        },
        {
          "range": {
            "@timestamp": {
              "gte": "2021-06-22T12:36:38.778Z",
              "lte": "2021-06-22T12:51:38.778Z",
              "format": "strict_date_optional_time"
            }
          }
        }
      ],
      "should": [],
      "must_not": []
    }
  }
}

Response:

{
  "took": 114809,
  "timed_out": false,
  "_shards": {
    "total": 48,
    "successful": 48,
    "skipped": 46,
    "failed": 0
  },
  "hits": {
    "total": 18588,
    "max_score": null,
    "hits": []
  },
  "aggregations": {
    "b8a65013-8337-436c-b9ca-e50c817a2c3b": {
      "doc_count_error_upper_bound": 0,
      "sum_other_doc_count": 0,
      "buckets": [
        {
          "key": "<ip_address>",
          "doc_count": 18588
        }
      ]
    }
  }
}

Based on the amount of docs (19k) and there only being 1 return key/bucket, I wouldn't expect this type of query to take this long.

If I run a similar query, but change out source.ip with destination.ip I get a much better response time:

"query": {
    "bool": {
      "must": [],
      "filter": [
        {
          "bool": {
            "should": [
              {
                "bool": {
                  "should": [
                    {
                      "query_string": {
                        "fields": [
                          "url.path"
                        ],
                        "query": "\\/_apps\\/<app_name>*"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              },
              {
                "bool": {
                  "should": [
                    {
                      "match_phrase": {
                        "url.original.text": "/_apps/<app_name>"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              }
            ],
            "minimum_should_match": 1
          }
        },
        {
          "bool": {
            "should": [
              {
                "bool": {
                  "should": [
                    {
                      "query_string": {
                        "fields": [
                          "url.path"
                        ],
                        "query": "\\/_apps\\/<app_name>*"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              },
              {
                "bool": {
                  "should": [
                    {
                      "match_phrase": {
                        "url.original.text": "/_apps/<app_name>"
                      }
                    }
                  ],
                  "minimum_should_match": 1
                }
              }
            ],
            "minimum_should_match": 1
          }
        },
        {
          "bool": {
            "minimum_should_match": 1,
            "should": [
              {
                "match_phrase": {
                  "host.name": "<host_1>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_2>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_3>"
                }
              },
              {
                "match_phrase": {
                  "host.name": "<host_4>"
                }
              }
            ]
          }
        },
        {
          "match_phrase": {
            "event.module": "iis"
          }
        },
        {
          "range": {
            "@timestamp": {
              "gte": "2021-06-22T12:36:38.778Z",
              "lte": "2021-06-22T12:51:38.778Z",
              "format": "strict_date_optional_time"
            }
          }
        }
      ],
      "should": [],
      "must_not": []
    }
  }

The response contains the same amount of records, but took significantly less time:

{
  "took": 8386,
  "timed_out": false,
  "_shards": {
    "total": 48,
    "successful": 48,
    "skipped": 46,
    "failed": 0
  },
  "hits": {
    "total": 18588,
    "max_score": null,
    "hits": []
  },
  "aggregations": {
    "b8a65013-8337-436c-b9ca-e50c817a2c3b": {
      "doc_count_error_upper_bound": 0,
      "sum_other_doc_count": 0,
      "buckets": [
        {
          "key": "<ip_address_1>",
          "doc_count": 4724
        },
        {
          "key": "<ip_address_2>",
          "doc_count": 4669
        },
        {
          "key": "<ip_address_3>",
          "doc_count": 4602
        },
        {
          "key": "<ip_address_4>",
          "doc_count": 4593
        }
      ]
    }
  }
}

What is the output from the _cluster/stats?pretty&human API?

@warkolm ; part 1 (stats output too large for 1 upload)

{
  "_nodes" : {
    "total" : 30,
    "successful" : 30,
    "failed" : 0
  },
  "cluster_name" : "<cluster_name>",
  "cluster_uuid" : "<cluster_id>",
  "timestamp" : 1624452863486,
  "status" : "green",
  "indices" : {
    "count" : 568,
    "shards" : {
      "total" : 1065,
      "primaries" : 568,
      "replication" : 0.875,
      "index" : {
        "shards" : {
          "min" : 1,
          "max" : 2,
          "avg" : 1.875
        },
        "primaries" : {
          "min" : 1,
          "max" : 1,
          "avg" : 1.0
        },
        "replication" : {
          "min" : 0.0,
          "max" : 1.0,
          "avg" : 0.875
        }
      }
    },
    "docs" : {
      "count" : 20365403756,
      "deleted" : 3056785
    },
    "store" : {
      "size" : "17.1tb",
      "size_in_bytes" : 18846873887033,
      "total_data_set_size" : "17.1tb",
      "total_data_set_size_in_bytes" : 18846873887033,
      "reserved" : "1.3tb",
      "reserved_in_bytes" : 1472451092464
    },
    "fielddata" : {
      "memory_size" : "1.6mb",
      "memory_size_in_bytes" : 1709344,
      "evictions" : 0
    },
    "query_cache" : {
      "memory_size" : "7.1gb",
      "memory_size_in_bytes" : 7698452331,
      "total_count" : 999133093,
      "hit_count" : 183358716,
      "miss_count" : 815774377,
      "cache_size" : 182657,
      "cache_count" : 1793150,
      "evictions" : 1610493
    },
    "completion" : {
      "size" : "0b",
      "size_in_bytes" : 0
    },
    "segments" : {
      "count" : 10554,
      "memory" : "347.9mb",
      "memory_in_bytes" : 364860662,
      "terms_memory" : "124.8mb",
      "terms_memory_in_bytes" : 130865336,
      "stored_fields_memory" : "16.6mb",
      "stored_fields_memory_in_bytes" : 17454496,
      "term_vectors_memory" : "0b",
      "term_vectors_memory_in_bytes" : 0,
      "norms_memory" : "166.1kb",
      "norms_memory_in_bytes" : 170176,
      "points_memory" : "0b",
      "points_memory_in_bytes" : 0,
      "doc_values_memory" : "206.3mb",
      "doc_values_memory_in_bytes" : 216370654,
      "index_writer_memory" : "535.2mb",
      "index_writer_memory_in_bytes" : 561210656,
      "version_map_memory" : "2.5kb",
      "version_map_memory_in_bytes" : 2609,
      "fixed_bit_set" : "1.1gb",
      "fixed_bit_set_memory_in_bytes" : 1262522856,
      "max_unsafe_auto_id_timestamp" : 1624422616736,
      "file_sizes" : { }
    },
    "mappings" : {
      "field_types" : [
        {
          "name" : "alias",
          "count" : 3903,
          "index_count" : 130,
          "script_count" : 0
        },
        {
          "name" : "binary",
          "count" : 11,
          "index_count" : 11,
          "script_count" : 0
        },
        {
          "name" : "boolean",
          "count" : 18918,
          "index_count" : 470,
          "script_count" : 0
        },
        {
          "name" : "byte",
          "count" : 32,
          "index_count" : 32,
          "script_count" : 0
        },
        {
          "name" : "constant_keyword",
          "count" : 81,
          "index_count" : 27,
          "script_count" : 0
        },
        {
          "name" : "date",
          "count" : 16768,
          "index_count" : 535,
          "script_count" : 0
        },
        {
          "name" : "date_nanos",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "date_range",
          "count" : 11,
          "index_count" : 11,
          "script_count" : 0
        },
        {
          "name" : "double",
          "count" : 9649,
          "index_count" : 227,
          "script_count" : 0
        },
        {
          "name" : "double_range",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "flattened",
          "count" : 1135,
          "index_count" : 49,
          "script_count" : 0
        },
        {
          "name" : "float",
          "count" : 8302,
          "index_count" : 312,
          "script_count" : 0
        },
        {
          "name" : "float_range",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "geo_point",
          "count" : 2105,
          "index_count" : 309,
          "script_count" : 0
        },
        {
          "name" : "geo_shape",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "half_float",
          "count" : 563,
          "index_count" : 155,
          "script_count" : 0
        },
        {
          "name" : "histogram",
          "count" : 6,
          "index_count" : 6,
          "script_count" : 0
        },
        {
          "name" : "integer",
          "count" : 1369,
          "index_count" : 183,
          "script_count" : 0
        },
        {
          "name" : "integer_range",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "ip",
          "count" : 9729,
          "index_count" : 259,
          "script_count" : 0
        },
        {
          "name" : "ip_range",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "keyword",
          "count" : 458183,
          "index_count" : 535,
          "script_count" : 0
        },
        {
          "name" : "long",
          "count" : 141692,
          "index_count" : 526,
          "script_count" : 0
        },
        {
          "name" : "long_range",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "nested",
          "count" : 670,
          "index_count" : 217,
          "script_count" : 0
        },
        {
          "name" : "object",
          "count" : 155382,
          "index_count" : 532,
          "script_count" : 0
        },
        {
          "name" : "scaled_float",
          "count" : 3414,
          "index_count" : 90,
          "script_count" : 0
        },
        {
          "name" : "shape",
          "count" : 2,
          "index_count" : 2,
          "script_count" : 0
        },
        {
          "name" : "short",
          "count" : 5104,
          "index_count" : 102,
          "script_count" : 0
        },
        {
          "name" : "text",
          "count" : 16513,
          "index_count" : 379,
          "script_count" : 0
        },
        {
          "name" : "wildcard",
          "count" : 6,
          "index_count" : 6,
          "script_count" : 0
        }
      ],
      "runtime_field_types" : [
        {
          "name" : "keyword",
          "count" : 4,
          "index_count" : 2,
          "scriptless_count" : 0,
          "shadowed_count" : 0,
          "lang" : [
            "painless"
          ],
          "lines_max" : 37,
          "lines_total" : 74,
          "chars_max" : 10415,
          "chars_total" : 20676,
          "source_max" : 0,
          "source_total" : 0,
          "doc_max" : 148,
          "doc_total" : 298
        },
        {
          "name" : "long",
          "count" : 4,
          "index_count" : 2,
          "scriptless_count" : 0,
          "shadowed_count" : 0,
          "lang" : [
            "painless"
          ],
          "lines_max" : 5,
          "lines_total" : 12,
          "chars_max" : 145,
          "chars_total" : 478,
          "source_max" : 0,
          "source_total" : 0,
          "doc_max" : 2,
          "doc_total" : 6
        }
      ]
    },
    "analysis" : {
      "char_filter_types" : [ ],
      "tokenizer_types" : [ ],
      "filter_types" : [ ],
      "analyzer_types" : [ ],
      "built_in_char_filters" : [ ],
      "built_in_tokenizers" : [ ],
      "built_in_filters" : [ ],
      "built_in_analyzers" : [
        {
          "name" : "simple",
          "count" : 18,
          "index_count" : 9
        },
        {
          "name" : "whitespace",
          "count" : 50,
          "index_count" : 50
        }
      ]
    },
    "versions" : [
      {
        "version" : "7.11.1",
        "index_count" : 13,
        "primary_shard_count" : 13,
        "total_primary_size" : "1.5mb",
        "total_primary_bytes" : 1654988
      },
      {
        "version" : "7.12.0",
        "index_count" : 16,
        "primary_shard_count" : 16,
        "total_primary_size" : "77.9gb",
        "total_primary_bytes" : 83660385032
      },
      {
        "version" : "7.12.1",
        "index_count" : 358,
        "primary_shard_count" : 358,
        "total_primary_size" : "6.8tb",
        "total_primary_bytes" : 7543354605658
      },
      {
        "version" : "7.13.1",
        "index_count" : 59,
        "primary_shard_count" : 59,
        "total_primary_size" : "1.4tb",
        "total_primary_bytes" : 1556931597899
      },
      {
        "version" : "7.13.2",
        "index_count" : 122,
        "primary_shard_count" : 122,
        "total_primary_size" : "1.8tb",
        "total_primary_bytes" : 2057798263046
      }
    ]
  },
  "nodes" : {
    "count" : {
      "total" : 30,
      "coordinating_only" : 0,
      "data" : 0,
      "data_cold" : 6,
      "data_content" : 6,
      "data_frozen" : 0,
      "data_hot" : 6,
      "data_warm" : 6,
      "ingest" : 3,
      "master" : 3,
      "ml" : 3,
      "remote_cluster_client" : 24,
      "transform" : 0,
      "voting_only" : 0
    },
    "versions" : [
      "7.13.2"
    ],
    "os" : {
      "available_processors" : 216,
      "allocated_processors" : 216,
      "names" : [
        {
          "name" : "Linux",
          "count" : 30
        }
      ],
      "pretty_names" : [
        {
          "pretty_name" : "CentOS Linux 8",
          "count" : 30
        }
      ],
      "architectures" : [
        {
          "arch" : "amd64",
          "count" : 30
        }
      ],
      "mem" : {
        "total" : "396gb",
        "total_in_bytes" : 425201762304,
        "free" : "36.3gb",
        "free_in_bytes" : 39052492800,
        "used" : "359.6gb",
        "used_in_bytes" : 386149269504,
        "free_percent" : 9,
        "used_percent" : 91
      }
    },
    "process" : {
      "cpu" : {
        "percent" : 23
      },
      "open_file_descriptors" : {
        "min" : 927,
        "max" : 2250,
        "avg" : 1307
      }
    }
  }
}

part 2


"jvm" : {
      "max_uptime" : "8d",
      "max_uptime_in_millis" : 691630288,
      "versions" : [
        {
          "version" : "16",
          "vm_name" : "OpenJDK 64-Bit Server VM",
          "vm_version" : "16+36",
          "vm_vendor" : "AdoptOpenJDK",
          "bundled_jdk" : true,
          "using_bundled_jdk" : true,
          "count" : 30
        }
      ],
      "mem" : {
        "heap_used" : "86.3gb",
        "heap_used_in_bytes" : 92768325664,
        "heap_max" : "198gb",
        "heap_max_in_bytes" : 212600881152
      },
      "threads" : 3431
    },
    "fs" : {
      "total" : "251.4tb",
      "total_in_bytes" : 276467787300864,
      "free" : "215.2tb",
      "free_in_bytes" : 236688693555200,
      "available" : "215.2tb",
      "available_in_bytes" : 236688693555200
    },
    "plugins" : [
      {
        "name" : "repository-s3",
        "version" : "7.13.2",
        "elasticsearch_version" : "7.13.2",
        "java_version" : "1.8",
        "description" : "The S3 repository plugin adds S3 repositories",
        "classname" : "org.elasticsearch.repositories.s3.S3RepositoryPlugin",
        "extended_plugins" : [ ],
        "has_native_controller" : false,
        "licensed" : false,
        "type" : "isolated"
      }
    ],
    "network_types" : {
      "transport_types" : {
        "security4" : 30
      },
      "http_types" : {
        "security4" : 30
      }
    },
    "discovery_types" : {
      "zen" : 30
    },
    "packaging_types" : [
      {
        "flavor" : "default",
        "type" : "docker",
        "count" : 30
      }
    ],
    "ingest" : {
      "number_of_pipelines" : 237,
      "processor_stats" : {
        "append" : {
          "count" : 39453533,
          "failed" : 0,
          "current" : 0,
          "time" : "1.6m",
          "time_in_millis" : 96263
        },
        "conditional" : {
          "count" : 1111343822,
          "failed" : 3190568,
          "current" : 0,
          "time" : "5.1h",
          "time_in_millis" : 18566664
        },
        "convert" : {
          "count" : 265791220,
          "failed" : 1777264,
          "current" : 0,
          "time" : "6m",
          "time_in_millis" : 361953
        },
        "date" : {
          "count" : 188363017,
          "failed" : 16049,
          "current" : 0,
          "time" : "54.6m",
          "time_in_millis" : 3280819
        },
        "dissect" : {
          "count" : 133440741,
          "failed" : 2571,
          "current" : 0,
          "time" : "19.3m",
          "time_in_millis" : 1159381
        },
        "dot_expander" : {
          "count" : 11417229,
          "failed" : 0,
          "current" : 0,
          "time" : "19.4s",
          "time_in_millis" : 19467
        },
        "foreach" : {
          "count" : 0,
          "failed" : 0,
          "current" : 0,
          "time" : "0s",
          "time_in_millis" : 0
        },
        "geoip" : {
          "count" : 383561016,
          "failed" : 0,
          "current" : 0,
          "time" : "4h",
          "time_in_millis" : 14447632
        },
        "grok" : {
          "count" : 396197467,
          "failed" : 4534898,
          "current" : 0,
          "time" : "1.3h",
          "time_in_millis" : 5038247
        },
        "gsub" : {
          "count" : 0,
          "failed" : 0,
          "current" : 0,
          "time" : "0s",
          "time_in_millis" : 0
        },
        "join" : {
          "count" : 0,
          "failed" : 0,
          "current" : 0,
          "time" : "0s",
          "time_in_millis" : 0
        },
        "json" : {
          "count" : 2597499,
          "failed" : 9149,
          "current" : 0,
          "time" : "23.5s",
          "time_in_millis" : 23527
        },
        "kv" : {
          "count" : 3190568,
          "failed" : 0,
          "current" : 0,
          "time" : "6m",
          "time_in_millis" : 365996
        },
        "lowercase" : {
          "count" : 14636465,
          "failed" : 0,
          "current" : 0,
          "time" : "14.5s",
          "time_in_millis" : 14502
        },
        "pipeline" : {
          "count" : 1674841,
          "failed" : 0,
          "current" : 0,
          "time" : "3.5m",
          "time_in_millis" : 210397
        },
        "remove" : {
          "count" : 721232057,
          "failed" : 4357484,
          "current" : 0,
          "time" : "33.7m",
          "time_in_millis" : 2025241
        },
        "rename" : {
          "count" : 1294107276,
          "failed" : 111053,
          "current" : 0,
          "time" : "1h",
          "time_in_millis" : 3843930
        },
        "script" : {
          "count" : 39608305,
          "failed" : 765,
          "current" : 0,
          "time" : "31.1m",
          "time_in_millis" : 1866243
        },
        "set" : {
          "count" : 438959338,
          "failed" : 0,
          "current" : 0,
          "time" : "1.1h",
          "time_in_millis" : 4152636
        },
        "split" : {
          "count" : 0,
          "failed" : 0,
          "current" : 0,
          "time" : "0s",
          "time_in_millis" : 0
        },
        "uppercase" : {
          "count" : 0,
          "failed" : 0,
          "current" : 0,
          "time" : "0s",
          "time_in_millis" : 0
        },
        "urldecode" : {
          "count" : 37270096,
          "failed" : 0,
          "current" : 0,
          "time" : "3.2m",
          "time_in_millis" : 192492
        },
        "user_agent" : {
          "count" : 186924584,
          "failed" : 0,
          "current" : 0,
          "time" : "11.4m",
          "time_in_millis" : 684697
        }
      }

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.