7.16 event loop delay value incorrect

[rudolf]

An idle 7.16 cluster with monitoring shows an event loop delay of 3 hours (11005301 ms)! This cannot be accurate because response times are still at most 1000 ms.

This appears to be a bug in the event loop delay collector not the monitoring app because the same data is present in the monitoring-* indices.

[elasticmachine]

Pinging @elastic/kibana-core (Team:Core)

[TinaHeiligers]

After digging into this it looks like the "bug" is related to the units in which we store the data:

Node's native monitorEventLoopDelay returns the data in nanoseconds:

"Creates an IntervalHistogram object that samples and reports the event loop delay over time. The delays will be reported in nanoseconds."

while Monitoring assumes it to be in milliseconds.

We have a few options here:

1. Handle the conversion at data storage level: convert the raw data on collection from nanoseconds to milliseconds (and add a comment about why this is needed):

    const lastUpdated = new Date();
    this.loopMonitor.disable();
    const { min, max, mean, exceeds, stddev } = this.loopMonitor;

    const collectedData: IntervalHistogram = {
      min: min / 1000000,
      max: max / 1000000,
      mean: mean / 1000000,
      exceeds: exceeds / 1000000,
      stddev: stddev / 1000000,
      fromTimestamp: this.fromTimestamp.toISOString(),
      lastUpdatedAt: lastUpdated.toISOString(),
      percentiles: {
        50: this.loopMonitor.percentile(50) / 1000000,
        75: this.loopMonitor.percentile(75) / 1000000,
        95: this.loopMonitor.percentile(95) / 1000000,
        99: this.loopMonitor.percentile(99) / 1000000,
      },
    };

    this.loopMonitor.enable();
    return collectedData;
  }

Or
2. Handle ns -> ms metrics conversion on consumer side: i.e. Change units in event_loop_delay visualization to ns rather than ms

OR convert data from ns -> ms before display.

We convert from ns to ms in track_threshold but I'm not sure if there are other consumers who treat the data as ns rather than ms.

@rudolf WDYT?

[mshustov]

Nanoseconds aren't human-friendly. It's hard to say whether 1080000ns or 108000ns is fast enough or not. However, the difference between 1ms and 0.1ms is easier to spot for a human eye.
Also, we aren't interested in small fluctuations of the event loop delay to justify nanoseconds usage.
IMO there is no good reason to change the current default, so I'd better do with the option 1. Even though, changes in event_loop_delay_histogram units might affect downstream plugins.

[TinaHeiligers]

there is no good reason to change the current default

Is there a list of default units Kibana uses somewhere? If not, maybe it might be a good idea to document that, both for development guidance and for end-users.

[mshustov]

If not, maybe it might be a good idea to document that, both for development guidance and for end-users.

I don't know to be honest, but I think there is no one-fits-all solution. The units are domain-specific: for performance metrics, we can use nanoseconds; for a backup copying period, we can specify seconds or minutes.
We can start with adding units in form of the comments for the Core public API. Probably, Monitoring caught the problem earlier if Core documented event_loop_delay_histogram uses nanoseconds units.

[rudolf]

Can you test what happens on 7.15 or 7.14? I'm not sure when this regression was introduced, but it used to show the correct value. I would guess that we always used to store ms values but that the Nodejs v16 upgrade changed the units to ns.

If this is the case, I think we should continue to store these values in ms so that a user can compare event-loop monitoring data from before and after an upgrade from e.g. 7.14 to 7.16.

[TinaHeiligers]

Probably, Monitoring caught the problem earlier if Core documented event_loop_delay_histogram uses nanoseconds units.

@mshustov There is a comment in the IntervalHistogram interface.
To prevent this happening again, where is the best place to add the units? In the interface's keys?

Can you test what happens on 7.15 or 7.14?

@rudolf I spun up a 7.14 deployment on cloud and the order of magnitudes comparison between Event loop Delay and Client Response Times shows that the delays are about 2 orders of magnitude less than the response times

For details of how this bug was introduced, see #118447