Slower Query Response Times - Intermittent

Hi there,

We recently noticed that some of the queries were having high response times like 12-15 seconds compared to others which were in miliseconds.

We have a query layer (Spring Boot App) which uses RestHighLevelClient to fire queries to ES Nodes.

We pulled out the queries from the logs and ran the same using postman directly to ES nodes and they seem to be performing well.

We have 5 ES nodes (7.10) and each box is 16 GB with 50% allocated to ES. The Active Primary Shards are 25 in our cluster and Total Active Shards are 50.

In total we have around 25 indexes.

We have noticed that the performance degrades sometimes where some queries start showing slower response times but then soon this goes away.

Please help

It sounds like a refresh effect.
If the index is not often queried, it will stop refreshing the index to act creating too many segments.

Is that happening in production or only when running your tests?

Hi David, thanks for your response.

The indexes are queried often. It happens in production as well.

We ran a load test of 20 users and we could see the behavior frequently.

Thanks,
Amit

I'd look at Index modules | Elasticsearch Reference [7.11] | Elastic

And see if this helps.

How often to perform a refresh operation, which makes recent changes to the index visible to search. Defaults to 1s . Can be set to -1 to disable refresh. If this setting is not explicitly set, shards that haven’t seen search traffic for at least index.search.idle.after seconds will not receive background refreshes until they receive a search request. Searches that hit an idle shard where a refresh is pending will wait for the next background refresh (within 1s ). This behavior aims to automatically optimize bulk indexing in the default case when no searches are performed. In order to opt out of this behavior an explicit value of 1s should set as the refresh interval.

Hi David, yes the refresh operation is default in our case which means 1s.

The index.search.idle.after is also default which is 30 seconds.

Does it have to be related to how frequently we index documents in our index. We are indexing almost every 2 hours. Can you guide us what value we should use here?

Also all our nodes are having default roles. Will it help if I have specific indexing nodes? All we want to ensure if that data nodes on which the search is being performed are optimized for queries with minimal impact to customer.

Thanks for all your help.

Also here is the cluster stats from our environment. If there is any specific thing you can point in this which indicates something is not right.

{
  "_nodes": {
    "total": 5,
    "successful": 5,
    "failed": 0
  },
  "cluster_name": "kcom-production",
  "cluster_uuid": "MbdtdJqbQeSsEI-n67PaQA",
  "timestamp": 1615277226374,
  "status": "green",
  "indices": {
    "count": 25,
    "shards": {
      "total": 50,
      "primaries": 25,
      "replication": 1,
      "index": {
        "shards": {
          "min": 2,
          "max": 2,
          "avg": 2
        },
        "primaries": {
          "min": 1,
          "max": 1,
          "avg": 1
        },
        "replication": {
          "min": 1,
          "max": 1,
          "avg": 1
        }
      }
    },
    "docs": {
      "count": 11071220,
      "deleted": 1126448
    },
    "store": {
      "size_in_bytes": 14783826840,
      "reserved_in_bytes": 0
    },
    "fielddata": {
      "memory_size_in_bytes": 667160,
      "evictions": 0
    },
    "query_cache": {
      "memory_size_in_bytes": 48156246,
      "total_count": 335946247,
      "hit_count": 63218628,
      "miss_count": 272727619,
      "cache_size": 12181,
      "cache_count": 1554431,
      "evictions": 1542250
    },
    "completion": {
      "size_in_bytes": 0
    },
    "segments": {
      "count": 385,
      "memory_in_bytes": 13349014,
      "terms_memory_in_bytes": 10357320,
      "stored_fields_memory_in_bytes": 372024,
      "term_vectors_memory_in_bytes": 0,
      "norms_memory_in_bytes": 1727232,
      "points_memory_in_bytes": 0,
      "doc_values_memory_in_bytes": 892438,
      "index_writer_memory_in_bytes": 14255520,
      "version_map_memory_in_bytes": 0,
      "fixed_bit_set_memory_in_bytes": 755888,
      "max_unsafe_auto_id_timestamp": 1612078346328,
      "file_sizes": {}
    },
    "mappings": {
      "field_types": [
        {
          "name": "date",
          "count": 17,
          "index_count": 17
        },
        {
          "name": "double",
          "count": 58,
          "index_count": 2
        },
        {
          "name": "float",
          "count": 4,
          "index_count": 2
        },
        {
          "name": "keyword",
          "count": 2840,
          "index_count": 25
        },
        {
          "name": "long",
          "count": 1269,
          "index_count": 5
        },
        {
          "name": "nested",
          "count": 7,
          "index_count": 4
        },
        {
          "name": "object",
          "count": 679,
          "index_count": 8
        },
        {
          "name": "text",
          "count": 3038,
          "index_count": 25
        }
      ]
    },
    "analysis": {
      "char_filter_types": [],
      "tokenizer_types": [],
      "filter_types": [
        {
          "name": "edge_ngram",
          "count": 24,
          "index_count": 13
        },
        {
          "name": "ngram",
          "count": 11,
          "index_count": 11
        }
      ],
      "analyzer_types": [
        {
          "name": "custom",
          "count": 58,
          "index_count": 14
        }
      ],
      "built_in_char_filters": [
        {
          "name": "icu_normalizer",
          "count": 11,
          "index_count": 11
        }
      ],
      "built_in_tokenizers": [
        {
          "name": "keyword",
          "count": 1,
          "index_count": 1
        },
        {
          "name": "kuromoji_tokenizer",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "nori_tokenizer",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "smartcn_tokenizer",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "standard",
          "count": 24,
          "index_count": 13
        }
      ],
      "built_in_filters": [
        {
          "name": "cjk_width",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "ja_stop",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "kuromoji_baseform",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "kuromoji_part_of_speech",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "kuromoji_stemmer",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "lowercase",
          "count": 58,
          "index_count": 14
        },
        {
          "name": "nori_part_of_speech",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "nori_readingform",
          "count": 11,
          "index_count": 11
        },
        {
          "name": "smartcn_stop",
          "count": 11,
          "index_count": 11
        }
      ],
      "built_in_analyzers": [
        {
          "name": "german",
          "count": 15,
          "index_count": 5
        },
        {
          "name": "kuromoji",
          "count": 42,
          "index_count": 9
        },
        {
          "name": "nori",
          "count": 42,
          "index_count": 9
        },
        {
          "name": "portuguese",
          "count": 15,
          "index_count": 5
        },
        {
          "name": "russian",
          "count": 15,
          "index_count": 5
        },
        {
          "name": "smartcn",
          "count": 42,
          "index_count": 9
        },
        {
          "name": "standard",
          "count": 42,
          "index_count": 9
        }
      ]
    }
  },
  "nodes": {
    "count": {
      "total": 5,
      "coordinating_only": 0,
      "data": 5,
      "ingest": 5,
      "master": 5,
      "ml": 5,
      "remote_cluster_client": 5,
      "transform": 5,
      "voting_only": 0
    },
    "versions": [
      "7.9.0"
    ],
    "os": {
      "available_processors": 40,
      "allocated_processors": 40,
      "names": [
        {
          "name": "Linux",
          "count": 5
        }
      ],
      "pretty_names": [
        {
          "pretty_name": "Amazon Linux 2",
          "count": 5
        }
      ],
      "mem": {
        "total_in_bytes": 81308901376,
        "free_in_bytes": 7094743040,
        "used_in_bytes": 74214158336,
        "free_percent": 9,
        "used_percent": 91
      }
    },
    "process": {
      "cpu": {
        "percent": 15
      },
      "open_file_descriptors": {
        "min": 447,
        "max": 474,
        "avg": 461
      }
    },
    "jvm": {
      "max_uptime_in_millis": 3198760874,
      "versions": [
        {
          "version": "14.0.1",
          "vm_name": "OpenJDK 64-Bit Server VM",
          "vm_version": "14.0.1+7",
          "vm_vendor": "AdoptOpenJDK",
          "bundled_jdk": true,
          "using_bundled_jdk": true,
          "count": 5
        }
      ],
      "mem": {
        "heap_used_in_bytes": 12763383280,
        "heap_max_in_bytes": 42949672960
      },
      "threads": 337
    },
    "fs": {
      "total_in_bytes": 1584664739840,
      "free_in_bytes": 1558152237056,
      "available_in_bytes": 1477537714176
    },
    "plugins": [
      {
        "name": "analysis-kuromoji",
        "version": "7.9.0",
        "elasticsearch_version": "7.9.0",
        "java_version": "1.8",
        "description": "The Japanese (kuromoji) Analysis plugin integrates Lucene kuromoji analysis module into elasticsearch.",
        "classname": "org.elasticsearch.plugin.analysis.kuromoji.AnalysisKuromojiPlugin",
        "extended_plugins": [],
        "has_native_controller": false
      },
      {
        "name": "analysis-icu",
        "version": "7.9.0",
        "elasticsearch_version": "7.9.0",
        "java_version": "1.8",
        "description": "The ICU Analysis plugin integrates the Lucene ICU module into Elasticsearch, adding ICU-related analysis components.",
        "classname": "org.elasticsearch.plugin.analysis.icu.AnalysisICUPlugin",
        "extended_plugins": [],
        "has_native_controller": false
      },
      {
        "name": "analysis-smartcn",
        "version": "7.9.0",
        "elasticsearch_version": "7.9.0",
        "java_version": "1.8",
        "description": "Smart Chinese Analysis plugin integrates Lucene Smart Chinese analysis module into elasticsearch.",
        "classname": "org.elasticsearch.plugin.analysis.smartcn.AnalysisSmartChinesePlugin",
        "extended_plugins": [],
        "has_native_controller": false
      },
      {
        "name": "analysis-nori",
        "version": "7.9.0",
        "elasticsearch_version": "7.9.0",
        "java_version": "1.8",
        "description": "The Korean (nori) Analysis plugin integrates Lucene nori analysis module into elasticsearch.",
        "classname": "org.elasticsearch.plugin.analysis.nori.AnalysisNoriPlugin",
        "extended_plugins": [],
        "has_native_controller": false
      }
    ],
    "network_types": {
      "transport_types": {
        "security4": 5
      },
      "http_types": {
        "security4": 5
      }
    },
    "discovery_types": {
      "zen": 5
    },
    "packaging_types": [
      {
        "flavor": "default",
        "type": "rpm",
        "count": 5
      }
    ],
    "ingest": {
      "number_of_pipelines": 2,
      "processor_stats": {
        "gsub": {
          "count": 0,
          "failed": 0,
          "current": 0,
          "time_in_millis": 0
        },
        "script": {
          "count": 0,
          "failed": 0,
          "current": 0,
          "time_in_millis": 0
        }
      }
    }
  }
}

I'd probably run:

  • A manual refresh after the injection of the new data
  • Run some searches on the new index to warm it up

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