I am using Elasticsearch profile API to check query performance. But I found the two values took and profile -> shards -> searches -> query -> time_in_nanos is very different.
Below is an output example:
{
"took" : 1139,
"timed_out" : false,
"_shards" : {
"total" : 1,
"successful" : 1,
"skipped" : 0,
"failed" : 0
},
"hits" : {
"total" : {
"value" : 238957,
"relation" : "eq"
},
"max_score" : 0.0,
...
"profile" : {
"shards" : [
{
"id" : "[-PQSJU3MQViBXwOaQN-IOg][mp-transaction-green][0]",
"searches" : [
{
"query" : [
{
"type" : "BoostQuery",
"description" : "(ConstantScore(+timestampUtc:[1640959200000 TO 9223372036854775807] +entityUuid:1b1404d7-5c2b-4a14-bf9e-8bdc494e7234))^0.0",
"time_in_nanos" : 103557672,
"breakdown" : {
"set_min_competitive_score_count" : 0,
"match_count" : 1,
"shallow_advance_count" : 0,
"set_min_competitive_score" : 0,
"next_doc" : 43104397,
"match" : 1133540,
"next_doc_count" : 238966,
"score_count" : 238957,
"compute_max_score_count" : 0,
"compute_max_score" : 0,
"advance" : 8247036,
"advance_count" : 18,
"score" : 6004966,
"build_scorer_count" : 43,
"create_weight" : 38801,
"shallow_advance" : 0,
"create_weight_count" : 1,
"build_scorer" : 45028932
},
"children" : [
{
"type" : "BooleanQuery",
"description" : "+timestampUtc:[1640959200000 TO 9223372036854775807] +entityUuid:1b1404d7-5c2b-4a14-bf9e-8bdc494e7234",
"time_in_nanos" : 83178924,
"breakdown" : {
"set_min_competitive_score_count" : 0,
"match_count" : 1,
"shallow_advance_count" : 0,
"set_min_competitive_score" : 0,
"next_doc" : 29133549,
"match" : 1132067,
"next_doc_count" : 238966,
"score_count" : 0,
"compute_max_score_count" : 0,
"compute_max_score" : 0,
"advance" : 8243103,
"advance_count" : 18,
"score" : 0,
"build_scorer_count" : 43,
"create_weight" : 29040,
"shallow_advance" : 0,
"create_weight_count" : 1,
"build_scorer" : 44641165
},
"children" : [
{
"type" : "IndexOrDocValuesQuery",
"description" : "timestampUtc:[1640959200000 TO 9223372036854775807]",
"time_in_nanos" : 31267154,
"breakdown" : {
"set_min_competitive_score_count" : 0,
"match_count" : 1,
"shallow_advance_count" : 0,
"set_min_competitive_score" : 0,
"next_doc" : 8401867,
"match" : 1123004,
"next_doc_count" : 238817,
"score_count" : 0,
"compute_max_score_count" : 0,
"compute_max_score" : 0,
"advance" : 294443,
"advance_count" : 9346,
"score" : 0,
"build_scorer_count" : 61,
"create_weight" : 5182,
"shallow_advance" : 0,
"create_weight_count" : 1,
"build_scorer" : 21442658
}
},
{
"type" : "TermQuery",
"description" : "entityUuid:1b1404d7-5c2b-4a14-bf9e-8bdc494e7234",
"time_in_nanos" : 21386796,
"breakdown" : {
"set_min_competitive_score_count" : 0,
"match_count" : 0,
"shallow_advance_count" : 0,
"set_min_competitive_score" : 0,
"next_doc" : 5486,
"match" : 0,
"next_doc_count" : 149,
"score_count" : 0,
"compute_max_score_count" : 0,
"compute_max_score" : 0,
"advance" : 12360641,
"advance_count" : 245078,
"score" : 0,
"build_scorer_count" : 61,
"create_weight" : 10808,
"shallow_advance" : 0,
"create_weight_count" : 1,
"build_scorer" : 9009861
}
}
]
}
]
}
],
"rewrite_time" : 10711,
"collector" : [
{
"name" : "SimpleTopScoreDocCollector",
"reason" : "search_top_hits",
"time_in_nanos" : 10057341
}
]
}
],
"aggregations" : [ ]
}
]
}
As you can see the value in took is 1139 which is a litter more than 1 seconds. But if I sum up all "time_in_nanos" which is only 248 milliseconds. Why do they have so much different? Is it because of network latency?