Any idea how to find bottlenecks on Elasticsearch side outside Lucene?
The actual profile breakdown is fast (<1ms) but the total "took" time is slow (209ms).
Example profile (redacted) below.
{
"took": 209,
"timed_out": false,
"_shards": {
"total": 1,
"successful": 1,
"skipped": 0,
"failed": 0
},
"hits": {
"total": {
"value": 36,
"relation": "eq"
},
"max_score": null,
"hits": []
},
"profile": {
"shards": [
{
"id": "<redacted>",
"searches": [
{
"query": [
{
"type": "BooleanQuery",
"description": "+key1:[ind1 TO ind1] x.y.keyword:string",
"time": "621.9micros",
"time_in_nanos": 621983,
"children": [
{
"type": "PointRangeQuery",
"description": "key1:[ind1 TO ind1]",
"time": "271.7micros",
"time_in_nanos": 271773,
"breakdown": {
"set_min_competitive_score_count": 0,
"match_count": 0,
"shallow_advance_count": 6,
"set_min_competitive_score": 0,
"next_doc": 1493,
"match": 0,
"next_doc_count": 5,
"score_count": 36,
"compute_max_score_count": 6,
"compute_max_score": 1879,
"advance": 11386,
"advance_count": 89,
"count_weight_count": 0,
"score": 16136,
"build_scorer_count": 54,
"create_weight": 459,
"shallow_advance": 2419,
"count_weight": 0,
"create_weight_count": 1,
"build_scorer": 238001
}
},
{
"type": "TermQuery",
"description": "x.y.keyword:string",
"time": "155.4micros",
"time_in_nanos": 155493,
"breakdown": {
"set_min_competitive_score_count": 0,
"match_count": 0,
"shallow_advance_count": 6,
"set_min_competitive_score": 0,
"next_doc": 0,
"match": 0,
"next_doc_count": 0,
"score_count": 3,
"compute_max_score_count": 3,
"compute_max_score": 22112,
"advance": 5063,
"advance_count": 5,
"count_weight_count": 0,
"score": 8304,
"build_scorer_count": 21,
"create_weight": 84603,
"shallow_advance": 5890,
"count_weight": 0,
"create_weight_count": 1,
"build_scorer": 29521
}
}
]
}
],
"rewrite_time": 11889,
"collector": [
{
"name": "SimpleFieldCollector",
"reason": "search_top_hits",
"time": "320.1micros",
"time_in_nanos": 320113
}
]
}
],
"aggregations": [],
"fetch": {
"type": "fetch",
"description": "",
"time": "763.9micros",
"time_in_nanos": 763967,
"breakdown": {
"load_stored_fields": 517772,
"load_source": 7290,
"load_stored_fields_count": 25,
"next_reader_count": 3,
"load_source_count": 25,
"next_reader": 42945
},
"debug": {
"stored_fields": [
"_id",
"_routing",
"_source"
]
},
"children": [
{
"type": "FetchSourcePhase",
"description": "",
"time": "7.4micros",
"time_in_nanos": 7408,
"breakdown": {
"process_count": 25,
"process": 6899,
"next_reader": 509,
"next_reader_count": 3
},
"debug": {
"fast_path": 25
}
},
{
"type": "StoredFieldsPhase",
"description": "",
"time": "6.9micros",
"time_in_nanos": 6983,
"breakdown": {
"process_count": 25,
"process": 5842,
"next_reader": 1141,
"next_reader_count": 3
}
}
]
}
}
]
}
}
Anyone know why?
Version:
"version": {
"number": "8.8.2",
"build_flavor": "default",
"build_type": "tar",
"build_hash": "98e1271edf932a480e4262a471281f1ee295ce6b",
"build_date": "2023-06-26T05:16:16.196344851Z",
"build_snapshot": false,
"lucene_version": "9.6.0",
"minimum_wire_compatibility_version": "7.17.0",
"minimum_index_compatibility_version": "7.0.0"
},