Debug slow search query

Hi everyone, I'm trying to debug a slow search query in Elasticsearch. Per-shard activities seems healthy but total amount to complete the request is surprisingly high. As I understand, the profile API does not include the work in the master node, network latency, etc. My question is: is there any other factor that I should investigate, maybe JVM gc activities or Lucene segment merges? I'm using Elasticsearch version 8.4.0. Any advices is appreciated. Thanks

{
  "took": 9554,
  "timed_out": false,
  "_shards": {
    "total": 1,
    "successful": 1,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": {
      "value": 203,
      "relation": "eq"
    },
    "max_score": null,
    "hits": [
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5077906632307986"
          ]
        },
        "sort": [
          1,
          1665457325000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5045247028894823"
          ]
        },
        "sort": [
          1,
          1665457306000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4420676144622424"
          ]
        },
        "sort": [
          1,
          1665394998000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2324930117559175"
          ]
        },
        "sort": [
          1,
          1665391586000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3100878013328342"
          ]
        },
        "sort": [
          1,
          1665391139000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_986600524769491"
          ]
        },
        "sort": [
          1,
          1665390597000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2288451224541056"
          ]
        },
        "sort": [
          1,
          1665390519000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4785893028107608"
          ]
        },
        "sort": [
          1,
          1665093688000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2451306934941214"
          ]
        },
        "sort": [
          1,
          1665093509000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3488420181243072"
          ]
        },
        "sort": [
          1,
          1665056702000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2994021280697086"
          ]
        },
        "sort": [
          1,
          1665056698000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4849822775043084"
          ]
        },
        "sort": [
          1,
          1665054175000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_6055589607792267"
          ]
        },
        "sort": [
          1,
          1665053432000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1765351246909842"
          ]
        },
        "sort": [
          1,
          1665037693000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5461667153902089"
          ]
        },
        "sort": [
          1,
          1664937698000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2730809253697348"
          ]
        },
        "sort": [
          1,
          1664896043000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_6195738477133721"
          ]
        },
        "sort": [
          1,
          1664793220000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3429350843756969"
          ]
        },
        "sort": [
          1,
          1664642540000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4553397411440695"
          ]
        },
        "sort": [
          1,
          1664449820000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5980946041966957"
          ]
        },
        "sort": [
          1,
          1664435848000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_109481374868497"
          ]
        },
        "sort": [
          1,
          1662795097000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3053920104638940"
          ]
        },
        "sort": [
          1,
          1662437608000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4312568428860422"
          ]
        },
        "sort": [
          1,
          1661767149000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3058602704182436"
          ]
        },
        "sort": [
          1,
          1661767112000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3192822807464805"
          ]
        },
        "sort": [
          1,
          1661572979000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4775534785880006"
          ]
        },
        "sort": [
          1,
          1661478740000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4685500944906285"
          ]
        },
        "sort": [
          1,
          1661140794000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5247103138688940"
          ]
        },
        "sort": [
          1,
          1660301777000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1587638787997100"
          ]
        },
        "sort": [
          1,
          1660290941000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2536010609772517"
          ]
        },
        "sort": [
          1,
          1659881833000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3392303364222592"
          ]
        },
        "sort": [
          1,
          1659688464000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1905665782791647"
          ]
        },
        "sort": [
          1,
          1658825504000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3791295304238548"
          ]
        },
        "sort": [
          1,
          1658825500000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4081153211921221"
          ]
        },
        "sort": [
          1,
          1658825496000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_2675325912483478"
          ]
        },
        "sort": [
          1,
          1658825496000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1530107703750103"
          ]
        },
        "sort": [
          1,
          1658825493000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1679589775415698"
          ]
        },
        "sort": [
          1,
          1658825465000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1628626143864068"
          ]
        },
        "sort": [
          1,
          1658825449000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3431613286926365"
          ]
        },
        "sort": [
          1,
          1658825448000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1365611260154090"
          ]
        },
        "sort": [
          1,
          1658825445000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1790420824405371"
          ]
        },
        "sort": [
          1,
          1658825439000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1736942243094893"
          ]
        },
        "sort": [
          1,
          1658825439000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1251293424950598"
          ]
        },
        "sort": [
          1,
          1658825437000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1363880743694898"
          ]
        },
        "sort": [
          1,
          1658116203000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1849043721785625"
          ]
        },
        "sort": [
          1,
          1657877716000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4324221041034216"
          ]
        },
        "sort": [
          1,
          1657528736000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4958295740872239"
          ]
        },
        "sort": [
          1,
          1655875191000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5700650850005034"
          ]
        },
        "sort": [
          1,
          1651638958000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4428347623869919"
          ]
        },
        "sort": [
          1,
          1646824014000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_5230067420343427"
          ]
        },
        "sort": [
          1,
          1646820766000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3421642657921890"
          ]
        },
        "sort": [
          1,
          1644810140000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_1553416614750602"
          ]
        },
        "sort": [
          1,
          1637897747000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_106258028529891"
          ]
        },
        "sort": [
          1,
          1635937389000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_100659042433660"
          ]
        },
        "sort": [
          1,
          1635840382000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_110559038092108"
          ]
        },
        "sort": [
          1,
          1635759685000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_100415862457432"
          ]
        },
        "sort": [
          1,
          1635758289000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_4679030402121885"
          ]
        },
        "sort": [
          1,
          1632923472000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3069059433215022"
          ]
        },
        "sort": [
          1,
          1632471738000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3419990208089406"
          ]
        },
        "sort": [
          1,
          1629707672000
        ]
      },
      {
        "_index": "conversations",
        "_score": null,
        "fields": {
          "compound_id": [
            "256469571178082:256469571178082_3913867028720911"
          ]
        },
        "sort": [
          1,
          1628151040000
        ]
      }
    ]
  },
  "profile": {
    "shards": [
      {
        "id": "[XAlEjpKER3ymqozhoU4vrA][conversations][11]",
        "searches": [
          {
            "query": [
              {
                "type": "ConstantScoreQuery",
                "description": "ConstantScore(#page_id:256469571178082 #type:INBOX)",
                "time_in_nanos": 5748715,
                "breakdown": {
                  "set_min_competitive_score_count": 0,
                  "match_count": 0,
                  "shallow_advance_count": 0,
                  "set_min_competitive_score": 0,
                  "next_doc": 2557330,
                  "match": 0,
                  "next_doc_count": 440,
                  "score_count": 0,
                  "compute_max_score_count": 0,
                  "compute_max_score": 0,
                  "advance": 207366,
                  "advance_count": 10,
                  "score": 0,
                  "build_scorer_count": 59,
                  "create_weight": 863171,
                  "shallow_advance": 0,
                  "create_weight_count": 1,
                  "build_scorer": 2120848
                },
                "children": [
                  {
                    "type": "BooleanQuery",
                    "description": "#page_id:256469571178082 #type:INBOX",
                    "time_in_nanos": 4553982,
                    "breakdown": {
                      "set_min_competitive_score_count": 0,
                      "match_count": 0,
                      "shallow_advance_count": 0,
                      "set_min_competitive_score": 0,
                      "next_doc": 2245961,
                      "match": 0,
                      "next_doc_count": 440,
                      "score_count": 0,
                      "compute_max_score_count": 0,
                      "compute_max_score": 0,
                      "advance": 199272,
                      "advance_count": 10,
                      "score": 0,
                      "build_scorer_count": 59,
                      "create_weight": 509797,
                      "shallow_advance": 0,
                      "create_weight_count": 1,
                      "build_scorer": 1598952
                    },
                    "children": [
                      {
                        "type": "TermQuery",
                        "description": "page_id:256469571178082",
                        "time_in_nanos": 1524005,
                        "breakdown": {
                          "set_min_competitive_score_count": 0,
                          "match_count": 0,
                          "shallow_advance_count": 0,
                          "set_min_competitive_score": 0,
                          "next_doc": 127445,
                          "match": 0,
                          "next_doc_count": 440,
                          "score_count": 0,
                          "compute_max_score_count": 0,
                          "compute_max_score": 0,
                          "advance": 705435,
                          "advance_count": 1780,
                          "score": 0,
                          "build_scorer_count": 69,
                          "create_weight": 69715,
                          "shallow_advance": 0,
                          "create_weight_count": 1,
                          "build_scorer": 621410
                        }
                      },
                      {
                        "type": "TermQuery",
                        "description": "type:INBOX",
                        "time_in_nanos": 876734,
                        "breakdown": {
                          "set_min_competitive_score_count": 0,
                          "match_count": 0,
                          "shallow_advance_count": 0,
                          "set_min_competitive_score": 0,
                          "next_doc": 0,
                          "match": 0,
                          "next_doc_count": 0,
                          "score_count": 0,
                          "compute_max_score_count": 0,
                          "compute_max_score": 0,
                          "advance": 756064,
                          "advance_count": 2100,
                          "score": 0,
                          "build_scorer_count": 30,
                          "create_weight": 17130,
                          "shallow_advance": 0,
                          "create_weight_count": 1,
                          "build_scorer": 103540
                        }
                      }
                    ]
                  }
                ]
              }
            ],
            "rewrite_time": 113785,
            "collector": [
              {
                "name": "SimpleFieldCollector",
                "reason": "search_top_hits",
                "time_in_nanos": 571551
              }
            ]
          }
        ],
        "aggregations": [],
        "fetch": {
          "type": "fetch",
          "description": "",
          "time_in_nanos": 3662649,
          "breakdown": {
            "load_stored_fields": 0,
            "load_source": 0,
            "load_stored_fields_count": 0,
            "next_reader_count": 4,
            "load_source_count": 0,
            "next_reader": 83144
          },
          "debug": {
            "stored_fields": []
          },
          "children": [
            {
              "type": "FetchDocValuesPhase",
              "description": "",
              "time_in_nanos": 272991,
              "breakdown": {
                "process_count": 60,
                "process": 233284,
                "next_reader": 39707,
                "next_reader_count": 4
              }
            }
          ]
        }
      }
    ]
  }
}

Solved. My testing environment consists of heavy index workload and very slight search workload. Also, I did not specify index.refresh_interval so every once in a while, I perform search request, it will have to wait for ES to perform refresh task first. Depends on the amount of updates accumulated in the buffers, it can take a few seconds to complete.

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