Add coordination time to profiler

[peternied]

Describe the bug
Took time on profiled request is 1.3 seconds, inspecting the shards search/aggregations times they are all under 460ms-339ms. This implies coordination had a substantial impact on the response time.

To Reproduce
Steps to reproduce the behavior:

1. Take a query from your ES instances slow log
2. Repeat the query with "profile":"true" until took time is above an acceptable threshold
3. Investigate the response by computing per shard - query / rewrite / collector time
4. Print the list of shard based times
5. Look for the 'longest running shard' to determine the bottleneck
6. Inspect the the coordinated time breakdown

Expected behavior
There would be a breakdown for coordination

Plugins
N/A

Screenshots
N/A

Host/Environment (please complete the following information):

• OS: Linux x64

Additional context
In some ways this is a feature request - but this is also an incomplete scenario to diagnose performance issues with this existing profiling tools.

[Bukhtawar]

I don't think it's a bug as the documentation clearly calls out the gap. We should plan on bridging this holistically

1. Network round trip
2. Time spent in queues
3. Time spent on coordinator fanning out
4. Time spent on coordinator merging responses

[Poojita-Raj]

Looking into this.

[peternied]

Here is an activity diagram of what it seems like is profiled, and those gaps around fan out, and node-to-node communication and waiting time are part of what I'd consider coordinator time that are absent.

Gist of the plantuml diagram

[Poojita-Raj]

These are the limitations with profiling that we are trying to bridge with this issue - Profile limitations

Namely, the top two issues is what we're trying to target right now:

1. Network overhead time measurement for node-to-node communication.
2. Time spent on coordinator fan out and coordinator fan in.

Network overhead time measurement for node-to-node communication

• Do we take the longest RTT or the average RTT (in wall clock nanoseconds) as a measurement for the network overhead in getting shard results from data nodes?

Time spent on coordinator fan out and coordinator fan in

The coordinating node (i.e., the node that receives the client request) executes it in 2 phases.

• Scatter phase: it forwards request to data nodes that hold the data to execute and return their results.
• Gather phase: it reduces individual results into a global result.

There are two questions to be answered here -

• Do we take into account time spent waiting for results from data nodes in gather phase?
• Do we consider scatter phase time and gather phase time separately or as a combined value called coordination time?

I'm putting possible choices/approaches for these metrics up for community transparency and to get opinions on alternate metrics that could be included!

[peternied]

@Poojita-Raj Why are we closing this issue?