Query performance degradation between 7.9.2 & 7.17.2

I recently upgraded one of my Elasticsearch clusters from 7.9.2 to 7.17.2. Immediately, I noticed that performance of my application (a Java app using the REST API) was degraded. So, I've been doing some side-by-side testing between the two ES versions. The biggest difference I see in terms of metrics (aside from elevated query response times) is that the query cache stats are very different between the two versions. I'm running identical queries against identical indices so I'm not sure why there is such a drastic difference. I wonder if the performance degradation is related to some change in query cache behavior?

My mapping looks like this:

        "mappings": {
            "dynamic": "false",
            "properties": {
                "eventId": {
                    "type": "keyword"
                },
                "lastModified": {
                    "type": "date",
                    "format": "strict_date_time_no_millis||strict_date_time"
                },
                "locations": {
                    "type": "flattened"
                },
                "processedTime": {
                    "type": "date",
                    "format": "strict_date_time_no_millis||strict_date_time"
                },
                "publishTime": {
                    "type": "date",
                    "format": "strict_date_time_no_millis||strict_date_time"
                },
                "upc": {
                    "type": "keyword"
                }
            }

A typical query includes a terms query against the upc field along with anywhere from one to six multi-match queries against fields in the flattened locations structure. For example:

{
  "size": 24,
  "query": {
    "bool": {
      "filter": [
        {
          "bool": {
            "must": [
              {
                "terms": {
                  "upc": [
                    "000000000001",
                    "000000000002",
                    "000000000003",
                    "000000000004",
                    "000000000005",
                    "000000000006",
                    "000000000007",
                    "000000000008",
                    "000000000009",
                    "000000000010",
                    "000000000011",
                    "000000000012",
                    "000000000013",
                    "000000000014",
                    "000000000015",
                    "000000000016",
                    "000000000017",
                    "000000000018",
                    "000000000019",
                    "000000000020",
                    "000000000021",
                    "000000000022",
                    "000000000023",
                    "000000000024"
                  ],
                  "boost": 1
                }
              },
              {
                "bool": {
                  "should": [
                    {
                      "multi_match": {
                        "query": "inStore",
                        "fields": [
                          "locations.location1.modality.modalities^1.0",
                          "locations.location2.modality.modalities^1.0",
                          "locations.location3.modality.modalities^1.0"
                        ],
                        "type": "best_fields",
                        "operator": "OR",
                        "slop": 0,
                        "prefix_length": 0,
                        "max_expansions": 50,
                        "zero_terms_query": "NONE",
                        "auto_generate_synonyms_phrase_query": true,
                        "fuzzy_transpositions": true,
                        "boost": 1,
                        "_name": "inStore"
                      }
                    }
                  ],
                  "adjust_pure_negative": true,
                  "boost": 1
                }
              }
            ],
            "adjust_pure_negative": true,
            "boost": 1
          }
        }
      ],
      "adjust_pure_negative": true,
      "boost": 1
    }
  },
  "_source": false
}

I ran a load test with the same fixed set of queries (all of the form described above) against 7.9.2 & 7.17.2. ES 7.9.2 showed much better performance (95th percentile response times < 20ms) than ES 7.17.2 (P95 >60ms). Looking specifically at ES metrics, ES 7.9.2 showed a ~20% query cache hit rate vs ES 7.17.2 showing a nearly 0% query cache hit rate. The hit rate was calculated from the index stats, taking # of hits / (# of hits + # of misses). CPU usage on the data nodes on 7.17.2 was over 2x that of 7.9.2.

I have a bunch of graphs and stuff I can certainly share, but I don't know what information would be most useful. At this point, I just don't understand the significant difference between ES versions given no change in our mapping or our query mix. Please let me know what other details I can provide to help?

Any guidance here would be much appreciated!

Bob

In hopes that this will help, here is a test I just ran between the two versions. I was running the exact same query over and over again. The query is a somewhat longer query of the form described above. There is a terms query with 25 values and several multi_match queries. All of the above run in a filter context.

I have read several older posts here and elsewhere about query cache and how it works. My understanding is that the terms query is not eligible for query cache but I think that the other parts of my query should be. Clearly, some parts of it are getting cached, though perhaps more in 7.9.2 than 7.17.2?

My query is at the bottom of this post (apologies for length, I'm not aware of a way to collapse/hide it). But, interestingly, here are query cache statistics captured during the test.

I notice a significantly larger query cache on 7.9.2 (both in terms of # of cache entries and memory size in bytes) and a ~45% query cache hit rate. On 7.17.2, I notice a much smaller query cache and a much lower hit rate of ~1% but an extremely high query cache lookup rate (which certainly influences the low hit rate). But, again with the same documents/mapping/query on both sides, why the very large difference?

I'm well out of my depth here so I'm really hoping someone who has a better understanding of how the query cache works can point me in the right direction. Obviously, I don't want to be stuck on 7.9.2 forever but the performance degradation is quite severe. Thank you in advance!

As promised, here is the query I'm running:

{
    "size": 25,
    "query": {
        "bool": {
            "filter": [
                {
                    "bool": {
                        "must": [
                            {
                                "terms": {
                                    "upc": [
                                        "000000000001",
                                        "000000000002",
                                        "000000000003",
                                        "000000000004",
                                        "000000000005",
                                        "000000000006",
                                        "000000000007",
                                        "000000000008",
                                        "000000000009",
                                        "000000000010",
                                        "000000000011",
                                        "000000000012",
                                        "000000000013",
                                        "000000000014",
                                        "000000000015",
                                        "000000000016",
                                        "000000000017",
                                        "000000000018",
                                        "000000000019",
                                        "000000000020",
                                        "000000000021",
                                        "000000000022",
                                        "000000000023",
                                        "000000000024",
                                        "000000000025"
                                    ],
                                    "boost": 1
                                }
                            },
                            {
                                "bool": {
                                    "should": [
                                        {
                                            "multi_match": {
                                                "query": "inStore",
                                                "fields": [
                                                    "locations.location1.modality.modalities^1.0",
                                                    "locations.location2.modality.modalities^1.0",
                                                    "locations.location3.modality.modalities^1.0"
                                                ],
                                                "type": "best_fields",
                                                "operator": "OR",
                                                "slop": 0,
                                                "prefix_length": 0,
                                                "max_expansions": 50,
                                                "zero_terms_query": "NONE",
                                                "auto_generate_synonyms_phrase_query": true,
                                                "fuzzy_transpositions": true,
                                                "boost": 1,
                                                "_name": "inStore"
                                            }
                                        },
                                        {
                                            "multi_match": {
                                                "query": "ship",
                                                "fields": [
                                                    "locations.location4.modality.modalities^1.0",
                                                    "locations.location5.modality.modalities^1.0",
                                                    "locations.location6.modality.modalities^1.0",
                                                    "locations.location7.modality.modalities^1.0",
                                                    "locations.location8.modality.modalities^1.0"
                                                ],
                                                "type": "best_fields",
                                                "operator": "OR",
                                                "slop": 0,
                                                "prefix_length": 0,
                                                "max_expansions": 50,
                                                "zero_terms_query": "NONE",
                                                "auto_generate_synonyms_phrase_query": true,
                                                "fuzzy_transpositions": true,
                                                "boost": 1,
                                                "_name": "ship"
                                            }
                                        },
                                        {
                                            "bool": {
                                                "must": [
                                                    {
                                                        "multi_match": {
                                                            "query": "delivery",
                                                            "fields": [
                                                                "locations.location9.modality.modalities^1.0",
                                                                "locations.location1.modality.modalities^1.0",
                                                                "locations.location10.modality.modalities^1.0",
                                                                "locations.location11.modality.modalities^1.0",
                                                                "locations.location12.modality.modalities^1.0"
                                                            ],
                                                            "type": "best_fields",
                                                            "operator": "OR",
                                                            "slop": 0,
                                                            "prefix_length": 0,
                                                            "max_expansions": 50,
                                                            "zero_terms_query": "NONE",
                                                            "auto_generate_synonyms_phrase_query": true,
                                                            "fuzzy_transpositions": true,
                                                            "boost": 1
                                                        }
                                                    },
                                                    {
                                                        "multi_match": {
                                                            "query": "delivery",
                                                            "fields": [
                                                                "locations.location13.modality.modalities^1.0",
                                                                "locations.location14.modality.modalities^1.0"
                                                            ],
                                                            "type": "best_fields",
                                                            "operator": "OR",
                                                            "slop": 0,
                                                            "prefix_length": 0,
                                                            "max_expansions": 50,
                                                            "zero_terms_query": "NONE",
                                                            "auto_generate_synonyms_phrase_query": true,
                                                            "fuzzy_transpositions": true,
                                                            "boost": 1
                                                        }
                                                    }
                                                ],
                                                "adjust_pure_negative": true,
                                                "boost": 1,
                                                "_name": "delivery"
                                            }
                                        },
                                        {
                                            "bool": {
                                                "must": [
                                                    {
                                                        "multi_match": {
                                                            "query": "pickup",
                                                            "fields": [
                                                                "locations.location1.modality.modalities^1.0"
                                                            ],
                                                            "type": "best_fields",
                                                            "operator": "OR",
                                                            "slop": 0,
                                                            "prefix_length": 0,
                                                            "max_expansions": 50,
                                                            "zero_terms_query": "NONE",
                                                            "auto_generate_synonyms_phrase_query": true,
                                                            "fuzzy_transpositions": true,
                                                            "boost": 1
                                                        }
                                                    },
                                                    {
                                                        "multi_match": {
                                                            "query": "pickup",
                                                            "fields": [
                                                                "locations.location13.modality.modalities^1.0",
                                                                "locations.location14.modality.modalities^1.0"
                                                            ],
                                                            "type": "best_fields",
                                                            "operator": "OR",
                                                            "slop": 0,
                                                            "prefix_length": 0,
                                                            "max_expansions": 50,
                                                            "zero_terms_query": "NONE",
                                                            "auto_generate_synonyms_phrase_query": true,
                                                            "fuzzy_transpositions": true,
                                                            "boost": 1
                                                        }
                                                    }
                                                ],
                                                "adjust_pure_negative": true,
                                                "boost": 1,
                                                "_name": "pickup"
                                            }
                                        }
                                    ],
                                    "adjust_pure_negative": true,
                                    "boost": 1
                                }
                            }
                        ],
                        "adjust_pure_negative": true,
                        "boost": 1
                    }
                }
            ],
            "adjust_pure_negative": true,
            "boost": 1
        }
    },
    "_source": false
}```

Hello!!
It's funny, the same thing happens to me. In my case we have seen this behavior when upgrading from elastic 7.1.1 to 7.17.2. The query times have gone up a lot in all percentiles.

I wonder if this is a known behavior and if in later versions it has been solved.
I hope someone can provide some light on this issue.

Would it be possible to provide the hot threads while running the query in a tight loop for both versions? that will hopefully show the path each query is taking.

2 Likes

Absolutely. Thanks in advance for any help you could provide.

I ran my query in a tight loop and hit /_nodes/hot_threads on both versions. I tended to get back an empty list of hot threads more often than not. But, I'll include a few samples here where the list was not empty in case they are useful. If there are different options on this call that would provide more useful output, please let me know. I used the defaults.

7.9.2 (including one sample here because they all were either empty or looked very similar to this on varying data nodes):

::: {elasticsearch-data-6}{7NmDXE8vRfa9TS-Vn-RNsQ}{zojqklCFTraVUJVgfwaeeA}{172.26.1.68}{172.26.1.68:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-5}{9G7CXVyOTGq6Tf1oW2qzvw}{_2jA2W5fRoKB3FLZsjDVWw}{172.26.4.132}{172.26.4.132:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-4}{sr_qWYG8RESm5ZlFzU2y8w}{TIoq-3FbTOK6YmdAHqy4ug}{172.26.4.164}{172.26.4.164:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
    0.3% (1.5ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-data-4][search][T#9]'
     8/10 snapshots sharing following 2 elements
       java.base@15/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
       java.base@15/java.lang.Thread.run(Thread.java:832)

::: {elasticsearch-data-7}{KtrwA9nySYGCdEr8c8UHkQ}{ZnzsPhSiRCyGF5eroNsvMg}{172.26.10.164}{172.26.10.164:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-4}{al1RofpSR0qmIK0HszbeXA}{yxAYUIf5T36jhTZx3f1uWg}{172.26.6.196}{172.26.6.196:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-10}{fuSarQTfQ1OtbeX1YhyB9g}{zckYDKRjS-ufMOaehlMKzQ}{172.26.8.132}{172.26.8.132:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-0}{LlKaHV_VS3uu4ezZS6qLfg}{oqA2rJoFR_mUGo8lKWjohA}{172.26.1.4}{172.26.1.4:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
    0.3% (1.4ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-data-0][search][T#21]'
     8/10 snapshots sharing following 2 elements
       java.base@15/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
       java.base@15/java.lang.Thread.run(Thread.java:832)

::: {elasticsearch-master-2}{pHkBGryeTKq9Q8FCuJ724Q}{8ztOqsAHT3KlgEoeNWes4w}{172.26.11.70}{172.26.11.70:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-1}{seWxj_56TA-kMfAFGpVEtw}{Y2JM9EHARUy8oONquuxMsg}{172.26.5.4}{172.26.5.4:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-0}{WfkLlUz-RHCIp63RBmMiXg}{on0s4gxjSK2CaoaMjCT6WA}{172.26.8.5}{172.26.8.5:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-2}{YHLcEL5tSxiuWQ24NCi6MA}{rhxavsd6SC2q68ZiYbyQKg}{172.26.1.36}{172.26.1.36:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-3}{Jg6ALs9MQL2NXs3iQOdjYQ}{rhobPKY_RmyWlJF0TP1lyA}{172.26.5.165}{172.26.5.165:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-8}{WCzJvdFVQ46rb0CeyAW-iA}{TEcv1FG3TTOtKa990cR9PA}{172.26.4.100}{172.26.4.100:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-5}{lyUpTTYITLKW67zmkt8CMw}{IK8gkUvwSmGowNDl-Imy0A}{172.26.1.100}{172.26.1.100:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-1}{Sz7nFNfvTAC5839umrLl8Q}{JNH6uZlDS8-5RU-xSrEVaw}{172.26.18.69}{172.26.18.69:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
    0.2% (1.2ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-master-1][transport_worker][T#2]'
     10/10 snapshots sharing following 3 elements
       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
       java.base@15/java.lang.Thread.run(Thread.java:832)

::: {elasticsearch-coordinating-2}{ORBNSEycQqO5Dnb8STr8Xw}{SZWIjDEaQT2INAHMJBeFqg}{172.26.6.164}{172.26.6.164:9300}{lr}{ml.machine_memory=28991029248, xpack.installed=true, transform.node=false, ml.max_open_jobs=20}
   Hot threads at 2022-06-27T13:52:08.452Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
    0.7% (3.7ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-coordinating-2][transport_worker][T#8]'
     8/10 snapshots sharing following 3 elements
       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
       java.base@15/java.lang.Thread.run(Thread.java:832)

::: {elasticsearch-data-3}{09z9b190QmqJkhH1yKQyGw}{A8RJ94IfQfOFERA9NaieFw}{172.26.13.196}{172.26.13.196:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-1}{AJ5Z-wXhTaaV_SMGildYRg}{i-pRokrwS7WuLQ35Qu4ZFA}{172.26.7.164}{172.26.7.164:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-9}{tGuU8EVpTzOs3Reir28qPw}{N5xRWCZjQ5WxeQ5XQ9w-LA}{172.26.11.196}{172.26.11.196:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.453Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-0}{Zy8Vh_ewRFmWIDBStBDeBw}{ZAKJlW7tRrynBoJMypFDQA}{172.26.5.196}{172.26.5.196:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=20, xpack.installed=true, transform.node=false}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-11}{C-t375ABSWWINAK2Hidklg}{7QO78ArkRSeUYu5F_TCeUQ}{172.26.13.228}{172.26.13.228:9300}{dilrt}{ml.machine_memory=60129542144, ml.max_open_jobs=20, xpack.installed=true, transform.node=true}
   Hot threads at 2022-06-27T13:52:08.454Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

7.27.2 (two samples here since they look slightly different from one another):

::: {elasticsearch-data-5}{GY3rekSER7Ge1eywHPgm3w}{FklSORT-TN2NRj8t9a8vfw}{172.25.227.198}{172.25.227.198:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.824Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-1}{QwaQC8fhSiu2-kpSqX6ZPw}{BySCFCpiQUK3nJ6XEwTaJw}{172.25.242.134}{172.25.242.134:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.824Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-3}{dAvivRevTB6KSwqNSfX41w}{2kN-H1V5Q1WFK9uZ_k6OHw}{172.25.242.166}{172.25.242.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.824Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-8}{JyDkGyuhTBytqfRfmG2s9g}{dD52sDk-RsWrJlWLtbh0Wg}{172.25.237.134}{172.25.237.134:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.824Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-9}{lpJlSKKkTGecucu8xohCwQ}{1oaBzTfvS-mmiipZbu5aFw}{172.25.244.198}{172.25.244.198:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-0}{bRCHn3sUSO6Kks9MeF9rKg}{CfPDc1hjR-S8Q5l5DasbCw}{172.25.230.205}{172.25.230.205:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-2}{FvaDCx2GQxeeR2as80oD2A}{R07ZdWlsSRqFlIrxQKsYtw}{172.25.244.6}{172.25.244.6:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-0}{ho7VJcDqR6-Wy6NvHwkZBQ}{lNFoXsJdRdKldkG9yXqJDQ}{172.25.233.6}{172.25.233.6:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-10}{NU8gl5z9R-2PfUM-TK6UNQ}{OZEF3_lwT7GFTK699pVHkw}{172.25.227.230}{172.25.227.230:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-6}{n9bGU5vbRHKdJVFHBx7rfw}{m68Yyor1R96kzp80K4WZ-w}{172.25.236.166}{172.25.236.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-2}{QPtue72eQGmFEcLrP94zOw}{Jx5EQMJyTsm2BWPhxDc_OQ}{172.25.233.40}{172.25.233.40:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
   100.0% [cpu=0.6%, other=99.4%] (500ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-coordinating-2][transport_worker][T#8]'
     10/10 snapshots sharing following 3 elements
       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
       java.base@17.0.2/java.lang.Thread.run(Thread.java:833)

::: {elasticsearch-data-7}{7uSAStS4TVCs6Rzo-OeLwA}{Y23cGCKIQCG_VAuKyNk0Mw}{172.25.235.102}{172.25.235.102:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-11}{vOLK2mc0TEKr_sGcsUj-tQ}{350ByzCSRc-f9MtXeEh93Q}{172.25.235.70}{172.25.235.70:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
   100.0% [cpu=0.3%, other=99.7%] (500ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-data-11][transport_worker][T#6]'
     10/10 snapshots sharing following 3 elements
       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
       java.base@17.0.2/java.lang.Thread.run(Thread.java:833)

::: {elasticsearch-coordinating-5}{CZpof6XdSPOCbVUTooQCqA}{fg_XVKJ2RiWT8x0X-ahu3w}{172.25.224.136}{172.25.224.136:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-1}{fQab7u1GRGy8qmp4YqHFrQ}{4XZuAfkLTz2_jndeo9he0A}{172.25.232.72}{172.25.232.72:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-3}{wcB7o77dQTSMoFXSvJg6UA}{vKQowWxLT7anyLS7_WQOmw}{172.25.232.200}{172.25.232.200:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-0}{fzX7CfKXQlK_Ta7nqQ8aDQ}{-VfsNbUUSUWN-M_bcKhH5A}{172.25.228.136}{172.25.228.136:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-4}{m6ZzZ280S0KJbWvu1a4V8A}{eii96ChKTD2mUa9tBFJbjQ}{172.25.237.166}{172.25.237.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-1}{jyaN56BzS82notUxzbRVFw}{HrKhbpwERWil6hviI52JvQ}{172.25.229.143}{172.25.229.143:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.826Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-2}{rB9JDpOgQ0urMxvAKRKcMg}{UflwoN0rQCuMtoqiFheDIQ}{172.25.229.207}{172.25.229.207:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:55:26.827Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-4}{bLPaepREQwKem0uhShPWXw}{bX3X6yaoRDyVBXXt7GMa-w}{172.25.239.137}{172.25.239.137:9300}{lr}{ml.machine_memory=28991029248, xpack.installed=true, transform.node=false, ml.max_open_jobs=512, ml.max_jvm_size=17179869184}
   Hot threads at 2022-06-27T13:55:26.825Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
::: {elasticsearch-master-1}{jyaN56BzS82notUxzbRVFw}{HrKhbpwERWil6hviI52JvQ}{172.25.229.143}{172.25.229.143:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.154Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-9}{lpJlSKKkTGecucu8xohCwQ}{1oaBzTfvS-mmiipZbu5aFw}{172.25.244.198}{172.25.244.198:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.142Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-1}{QwaQC8fhSiu2-kpSqX6ZPw}{BySCFCpiQUK3nJ6XEwTaJw}{172.25.242.134}{172.25.242.134:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.141Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-3}{wcB7o77dQTSMoFXSvJg6UA}{vKQowWxLT7anyLS7_WQOmw}{172.25.232.200}{172.25.232.200:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.139Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
   100.0% [cpu=0.5%, other=99.5%] (500ms out of 500ms) cpu usage by thread 'elasticsearch[elasticsearch-coordinating-3][transport_worker][T#7]'
     unique snapshot
       java.base@17.0.2/sun.nio.ch.SocketDispatcher.read0(Native Method)
       java.base@17.0.2/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:47)
       java.base@17.0.2/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:330)
       java.base@17.0.2/sun.nio.ch.IOUtil.read(IOUtil.java:284)
       java.base@17.0.2/sun.nio.ch.IOUtil.read(IOUtil.java:259)
       java.base@17.0.2/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:417)
       org.elasticsearch.transport.CopyBytesSocketChannel.readFromSocketChannel(CopyBytesSocketChannel.java:131)
       org.elasticsearch.transport.CopyBytesSocketChannel.doReadBytes(CopyBytesSocketChannel.java:116)
       io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151)
       io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
       io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:620)
       io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:583)
       io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
       java.base@17.0.2/java.lang.Thread.run(Thread.java:833)

::: {elasticsearch-master-0}{bRCHn3sUSO6Kks9MeF9rKg}{CfPDc1hjR-S8Q5l5DasbCw}{172.25.230.205}{172.25.230.205:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.174Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-1}{fQab7u1GRGy8qmp4YqHFrQ}{4XZuAfkLTz2_jndeo9he0A}{172.25.232.72}{172.25.232.72:9300}{lr}{ml.machine_memory=28991029248, xpack.installed=true, transform.node=false, ml.max_open_jobs=512, ml.max_jvm_size=17179869184}
   Hot threads at 2022-06-27T13:47:46.136Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-10}{NU8gl5z9R-2PfUM-TK6UNQ}{OZEF3_lwT7GFTK699pVHkw}{172.25.227.230}{172.25.227.230:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.142Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-11}{vOLK2mc0TEKr_sGcsUj-tQ}{350ByzCSRc-f9MtXeEh93Q}{172.25.235.70}{172.25.235.70:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.142Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-6}{n9bGU5vbRHKdJVFHBx7rfw}{m68Yyor1R96kzp80K4WZ-w}{172.25.236.166}{172.25.236.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.141Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-5}{GY3rekSER7Ge1eywHPgm3w}{FklSORT-TN2NRj8t9a8vfw}{172.25.227.198}{172.25.227.198:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.141Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-2}{FvaDCx2GQxeeR2as80oD2A}{R07ZdWlsSRqFlIrxQKsYtw}{172.25.244.6}{172.25.244.6:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.143Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-0}{ho7VJcDqR6-Wy6NvHwkZBQ}{lNFoXsJdRdKldkG9yXqJDQ}{172.25.233.6}{172.25.233.6:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.142Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-4}{m6ZzZ280S0KJbWvu1a4V8A}{eii96ChKTD2mUa9tBFJbjQ}{172.25.237.166}{172.25.237.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.141Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-2}{QPtue72eQGmFEcLrP94zOw}{Jx5EQMJyTsm2BWPhxDc_OQ}{172.25.233.40}{172.25.233.40:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.139Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-8}{JyDkGyuhTBytqfRfmG2s9g}{dD52sDk-RsWrJlWLtbh0Wg}{172.25.237.134}{172.25.237.134:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.143Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-5}{CZpof6XdSPOCbVUTooQCqA}{fg_XVKJ2RiWT8x0X-ahu3w}{172.25.224.136}{172.25.224.136:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.140Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-4}{bLPaepREQwKem0uhShPWXw}{bX3X6yaoRDyVBXXt7GMa-w}{172.25.239.137}{172.25.239.137:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.140Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-master-2}{rB9JDpOgQ0urMxvAKRKcMg}{UflwoN0rQCuMtoqiFheDIQ}{172.25.229.207}{172.25.229.207:9300}{lmr}{ml.machine_memory=4294967296, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=2147483648, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.150Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-7}{7uSAStS4TVCs6Rzo-OeLwA}{Y23cGCKIQCG_VAuKyNk0Mw}{172.25.235.102}{172.25.235.102:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.143Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-coordinating-0}{fzX7CfKXQlK_Ta7nqQ8aDQ}{-VfsNbUUSUWN-M_bcKhH5A}{172.25.228.136}{172.25.228.136:9300}{lr}{ml.machine_memory=28991029248, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=false}
   Hot threads at 2022-06-27T13:47:46.140Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {elasticsearch-data-3}{dAvivRevTB6KSwqNSfX41w}{2kN-H1V5Q1WFK9uZ_k6OHw}{172.25.242.166}{172.25.242.166:9300}{cdfhilrstw}{ml.machine_memory=60129542144, ml.max_open_jobs=512, xpack.installed=true, ml.max_jvm_size=17179869184, transform.node=true}
   Hot threads at 2022-06-27T13:47:46.143Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

One other thing I should mention. Late last week, I ran the same query repeatedly with query cache disabled in both versions and saw significantly degraded performance in 7.17.2 compared to 7.9.2 (7.17.2 query and fetch times were about 2x those of 7.9.2). I will try the same hot threads test with query cache disabled and reply back if it turns up anything that looks significantly different from above.

I mention this because I'd really been focused on the query cache metrics up until that point. And, maybe this data point will help someone with a much better understanding of the internal workings of Elasticsearch. :slight_smile:

UPDATE: I did this test and found basically the same results from hot threads. I got back either an empty list of hot threads or responses that looked similar to the ones above.

I plugged the query into the profiler in both versions. From what I can see, the result was the same ... everything in the query ultimately breaks down to a Term Query. Since I've seen in the documentation and in posts here that term queries are not query cacheable, I think I'm leaning toward the query cache not being the culprit here.

But, the other thing that the profiler output showed was that each bit of the query execution was slower on 7.17.2 than 7.9.2, which seems to imply that term query execution in general (at least for me) is slower. And, since my queries break down entirely into term queries I'm not sure what I can really do to tune that.

It seems like if there was an across-the-board performance degradation in newer versions that there would be more mention of it here. So, it seems like it must be something specific to how my queries are constructed or something.

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