Elasticsearch 6.0.0-rc2 - Searches take a long time to run; sometimes timeout

Elastic Stack Elasticsearch
1

Hello,

We're using Elasticsearch (6.0.0-rc2) in conjunction with Kibana, and have noticed that queries take a much longer time to run.

Has anything changed regarding index mappings from Elasticsearch 5.5 to 6.0.0-rc2?

Below you will find one of our index templates and a profile query response, when querying the last 6 hours (lasted 20 seconds).

Thank you.

Template:

{
  "order": 0,
  "index_patterns": [
    "my-index-*"
  ],
  "settings": {
    "index": {
      "number_of_shards": "18",
      "number_of_replicas": "3"
    }
  },
  "mappings": {
    "my-index": {
      "properties": {
        "Geo": {
          "type": "geo_point"
        },
        "AdID": {
          "type": "keyword"
        },
        "Type": {
          "type": "keyword"
        },
        "@timestamp": {
          "type": "date"
        },
        "CountryISO": {
          "type": "keyword"
        },
        "ASourceID": {
          "type": "keyword"
        },
        "Device": {
          "type": "keyword"
        },
        "Domain": {
          "ignore_above": 256,
          "type": "keyword"
        },
        "CreativeID": {
          "type": "keyword"
        },
        "PlVer": {
          "type": "keyword"
        }
      }
    }
  },
  "aliases": {}
}

Profile query output, which is unfortunately quite huge:
https://drive.google.com/file/d/1SA974zAyY1HnvSA3GSona7VzHKcSiUPe/view?usp=sharing

2

This seems like a very large number of shards, which could be affecting performance. How much data does each index hold? Have you read this blog post around shards and sharding??

Can you provide the full output of the cluster stats API to give us a better view of the cluster?

How many data nodes do you have in the cluster and what is their specification (CPU cores, RAM and type of storage)? What do CPU usage, disk I/O and iowait look like during the time the query executes?

It would also be useful if you could show what the query looks like and describe what you are looking to achieve with it. I do unfortunately not have time to go through several MB of query profile output.

Are you also indexing while querying?

3

Hi Christian,

Thank you for the reply.

Each index in the template ends up holding about 300GB of data (500 million records) per the day (we split indices by date).
We had previously decided upon that amount of shards when we had version 5.5.1 of the Elastic stack deployed, although with the space usage improvements brought by 6.x, the shard count dues indeed turn out to be quite high.
We are indeed indexing while querying. We have a setup which continuously sends data to the ES cluster for indexing, but we also have users which are querying for their day-to-day business-related needs.

The cluster consists of 51 nodes, spread out as it follows:

  • 3 master nodes - m3.xlarge AWS instances (15GB RAM, 8 vCPUs, 80GiB SSD storage)
  • 6 client nodes - c5.2xlarge AWS instances (16GB RAM, 8 vCPUs, 8GiB SSD storage)
  • 42 data nodes - i3.2xlarge AWS instances (61GB RAM, 8 vCPUs, 1900GiB NVMe SSD storage)

Cluster API output:

{
  "_nodes" : {
    "total" : 51,
    "successful" : 51,
    "failed" : 0
  },
  "cluster_name" : "elasticsearch-reporting",
  "timestamp" : 1510829886692,
  "status" : "green",
  "indices" : {
    "count" : 169,
    "shards" : {
      "total" : 4868,
      "primaries" : 1231,
      "replication" : 2.9545085296506906,
      "index" : {
        "shards" : {
          "min" : 2,
          "max" : 72,
          "avg" : 28.80473372781065
        },
        "primaries" : {
          "min" : 1,
          "max" : 18,
          "avg" : 7.284023668639053
        },
        "replication" : {
          "min" : 1.0,
          "max" : 41.0,
          "avg" : 2.8579881656804735
        }
      }
    },
    "docs" : {
      "count" : 9620886179,
      "deleted" : 265026
    },
    "store" : {
      "size" : "7.3tb",
      "size_in_bytes" : 8042730438419
    },
    "fielddata" : {
      "memory_size" : "187.7mb",
      "memory_size_in_bytes" : 196858872,
      "evictions" : 0
    },
    "query_cache" : {
      "memory_size" : "22.2gb",
      "memory_size_in_bytes" : 23859117412,
      "total_count" : 32678911,
      "hit_count" : 13103016,
      "miss_count" : 19575895,
      "cache_size" : 401768,
      "cache_count" : 552786,
      "evictions" : 151018
    },
    "completion" : {
      "size" : "0b",
      "size_in_bytes" : 0
    },
    "segments" : {
      "count" : 89077,
      "memory" : "14.1gb",
      "memory_in_bytes" : 15164679364,
      "terms_memory" : "9.8gb",
      "terms_memory_in_bytes" : 10570119973,
      "stored_fields_memory" : "2.8gb",
      "stored_fields_memory_in_bytes" : 3045454864,
      "term_vectors_memory" : "0b",
      "term_vectors_memory_in_bytes" : 0,
      "norms_memory" : "15.5mb",
      "norms_memory_in_bytes" : 16269056,
      "points_memory" : "1.3gb",
      "points_memory_in_bytes" : 1481102387,
      "doc_values_memory" : "49.3mb",
      "doc_values_memory_in_bytes" : 51733084,
      "index_writer_memory" : "609.3mb",
      "index_writer_memory_in_bytes" : 638958010,
      "version_map_memory" : "15mb",
      "version_map_memory_in_bytes" : 15732046,
      "fixed_bit_set" : "59kb",
      "fixed_bit_set_memory_in_bytes" : 60448,
      "max_unsafe_auto_id_timestamp" : 1510790401733,
      "file_sizes" : { }
    }
  },
  "nodes" : {
    "count" : {
      "total" : 51,
      "data" : 42,
      "coordinating_only" : 6,
      "master" : 3,
      "ingest" : 42
    },
    "versions" : [
      "6.0.0-rc2"
    ],
    "os" : {
      "available_processors" : 396,
      "allocated_processors" : 396,
      "names" : [
        {
          "name" : "Linux",
          "count" : 51
        }
      ],
      "mem" : {
        "total" : "2.5tb",
        "total_in_bytes" : 2848992215040,
        "free" : "41.8gb",
        "free_in_bytes" : 44894351360,
        "used" : "2.5tb",
        "used_in_bytes" : 2804097863680,
        "free_percent" : 2,
        "used_percent" : 98
      }
    },
    "process" : {
      "cpu" : {
        "percent" : 479
      },
      "open_file_descriptors" : {
        "min" : 1363,
        "max" : 2424,
        "avg" : 1885
      }
    },
    "jvm" : {
      "max_uptime" : "2.9d",
      "max_uptime_in_millis" : 258501345,
      "versions" : [
        {
          "version" : "1.8.0_151",
          "vm_name" : "Java HotSpot(TM) 64-Bit Server VM",
          "vm_version" : "25.151-b12",
          "vm_vendor" : "Oracle Corporation",
          "count" : 51
        }
      ],
      "mem" : {
        "heap_used" : "594.2gb",
        "heap_used_in_bytes" : 638116896024,
        "heap_max" : "1.4tb",
        "heap_max_in_bytes" : 1584612507648
      },
      "threads" : 7540
    },
    "fs" : {
      "total" : "71.5tb",
      "total_in_bytes" : 78616502906880,
      "free" : "63.7tb",
      "free_in_bytes" : 70123576582144,
      "available" : "60.1tb",
      "available_in_bytes" : 66132721008640
    },
    "plugins" : [
      {
        "name" : "discovery-ec2",
        "version" : "6.0.0-rc2",
        "description" : "The EC2 discovery plugin allows to use AWS API for the unicast discovery mechanism.",
        "classname" : "org.elasticsearch.discovery.ec2.Ec2DiscoveryPlugin",
        "has_native_controller" : false,
        "requires_keystore" : false
      },
      {
        "name" : "repository-s3",
        "version" : "6.0.0-rc2",
        "description" : "The S3 repository plugin adds S3 repositories",
        "classname" : "org.elasticsearch.repositories.s3.S3RepositoryPlugin",
        "has_native_controller" : false,
        "requires_keystore" : false
      },
      {
        "name" : "x-pack",
        "version" : "6.0.0-rc2",
        "description" : "Elasticsearch Expanded Pack Plugin",
        "classname" : "org.elasticsearch.xpack.XPackPlugin",
        "has_native_controller" : true,
        "requires_keystore" : true
      }
    ],
    "network_types" : {
      "transport_types" : {
        "security4" : 51
      },
      "http_types" : {
        "security4" : 51
      }
    }
  }
}
4

Due to the character amount limitation of a reply, I am attaching the continuation to this post.

The query is as follows, submitted to /my-index-*/_search. I've also made a cURL request to the endpoint, containing the query, and it took about 10 seconds before the response started streaming back and the took field in the response had a value of 9342

Node CPU usage while running the query barely seems to be affected. They're usually between 15-30% CPU usage. I/O wait is sitting at around 0.28-0.30 on most nodes.

{
  "size":0,
  "_source":{
    "excludes":[

    ]
  },
  "aggs":{
    "5":{
      "terms":{
        "field":"_type",
        "size":10000,
        "order":{
          "_count":"desc"
        }
      },
      "aggs":{
        "4":{
          "terms":{
            "field":"Domain",
            "size":10000,
            "order":{
              "_count":"desc"
            }
          },
          "aggs":{
            "3":{
              "terms":{
                "field":"ASourceID",
                "size":10000,
                "order":{
                  "_count":"desc"
                }
              },
              "aggs":{
                "2":{
                  "sum":{
                    "field":"NumberField1"
                  }
                }
              }
            }
          }
        }
      }
    }
  },
  "stored_fields":[
    "*"
  ],
  "script_fields":{
    "Profit":{
      "script":{
        "inline":"double numberField1 = 0;\ndouble numberField2 = 0;\n\nif (doc.containsKey('\''NumberField1'\''))  {\n  numberField1 = doc['\''NumberField1'\''].value; \n}\n\nif (doc.containsKey('\''NumberField2'\''))  {\n  numberField2 = doc['\''NumberField2'\''].value; \n}\n\nreturn numberField1 - numberField2;",
        "lang":"painless"
      }
    }
  },
  "docvalue_fields":[
    "@timestamp",
    "timestamp"
  ],
  "query":{
    "bool":{
      "must":[
        {
          "query_string":{
            "analyze_wildcard":true,
            "default_field":"*",
            "query":"(_type: my-index-type) AND NOT (ASourceID:0)"
          }
        },
        {
          "range":{
            "@timestamp":{
              "gte":1510768800000,
              "lte":1510790399999,
              "format":"epoch_millis"
            }
          }
        }
      ],
      "filter":[],
      "should":[],
      "must_not":[]
    }
  }
}
5

What is the cardinality of the _type field? It does look like this aggregation will be generating a very large number of buckets. Do you have monitoring enabled so you can see if this has any effect on heap usage?

I also do not understand why you do not calculate the Profit per record at ingest time so you do not need to use a scripted field.

6

The cardinality of the _type field corresponds with the number of index templates. Thus, for my-index1-*, my-index2-*, my-index3-* we would have my-index1, my-index2, my-index3 as possible values.
Currently we have 11 index templates set up, thus the cardinality of the _type field would be 11 when running the query for the my-* index pattern.
For that specific query, the cardinality would be 1, due to running the query for my-index-*.

Heap usage seems to be following same pattern across nodes

26
Screen Shot 2017-11-16 at 15.18.26.png1212×410 36.4 KB

We've recently started to compute the Profit field before ingestion time (under a different name), while also maintaining the scripted field up. This strategy will be applied until the fields added by both methods will reach parity, as we keep cleaning up old indices, which do not have the newly added, alternate, Profit field.

7

Aggregation internals is not my strength, but would you be able to set the size parameter closer to the real cardinality at the different levels to see if that makes any difference? It is worth noticing that each aggregation executes single-threaded per shard, although shards are processed in parallel. It looks like this aggregation only would target (find data) in a reasonably small number of shards, which would limit the amount of processing resources used. It may be that your current shard size is not optimal for your use case. It would be interesting to see how it performs with a larger number of smaller shards.

8

It is worth noticing that each aggregation executes single-threaded per shard, although shards are processed in parallel

We did not know that, thanks for the suggestion.

It may be that your current shard size is not optimal for your use case. It would be interesting to see how it performs with a larger number of smaller shards.

We used to have a larger number of shards, and then reduced them when we were still using Elasticsearch 5.5.1. That god rid of the issues we were having with the thread pool bulk size going up and freezing different nodes, but we didn't notice any performance degradation when doing that. Did something related to that change in the Elasticsearch internals?

9

I would recommend running the query with smaller size parameters and then gradually increase them to see how it affects performance. Also avoid setting the size needlessly large.

10

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