[Stack Monitoring] More detailed event loop diagnostics

[rudolf]

There's two ways to get more details about Kibana's event loop:

1. Enable debug level logs from the metrics.ops logger
   The metrics.ops logger will log the following fields:

    "process": {
        "uptime": 992,
        "memory": {
            "heap": {
                "usedInBytes": 1110837232
            }
        },
        "eventLoopDelay": null,
        "eventLoopDelayHistogram": {
            "50": 0,
            "95": 0,
            "99": 0
        },
        "pid": 21480
    },
    "host": {
        "os": {
            "load": {
                "1m": 4.28515625,
                "5m": 3.58837890625,
                "15m": 3.33642578125
            }
        }
    }
   

2. Using stack monitoring

       "process": {
          "uptime": {
            "ms": 60006745
          },
          "event_loop_delay": {
            "ms": 10.099492275303643
          },
          "memory": {
            "resident_set_size": {
              "bytes": 391475200
            },
            "heap": {
              "size_limit": {
                "bytes": 851443712
              },
              "total": {
                "bytes": 277549056
              },
              "used": {
                "bytes": 227331088
              }
            }
          }
        },
   

It would be useful if both diagnostics contained all the values in the IntervalHistogram type:

export interface IntervalHistogram {
  // The first timestamp the interval timer kicked in for collecting data points.
  fromTimestamp: string;
  // Last timestamp the interval timer kicked in for collecting data points.
  lastUpdatedAt: string;
  // The minimum recorded event loop delay.
  min: number;
  // The maximum recorded event loop delay.
  max: number;
  // The mean of the recorded event loop delays.
  mean: number;
  // The standard deviation of the recorded event loop delays.
  stddev: number;
  // An object detailing the accumulated percentile distribution.
  percentiles: {
    // 50th percentile of delays of the collected data points.
    50: number;
    // 75th percentile of delays of the collected data points.
    75: number;
    // 95th percentile of delays of the collected data points.
    95: number;
    // 99th percentile of delays of the collected data points.
    99: number;
  };
}```

[elasticmachine]

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

[smith]

Putting the "Platform Observability" label on this. When we decide to add this, it may be a metric from platform observability or added to the existing Stack Monitoring app.

[rudolf]

Specifically for testing performance optimisations looking at the maximum recorded event loop delay is often more useful than the mean since a single request causing a > 1s event loop delay is a problem even if the mean over 5s would be a lot lower.

[gsoldevila]

There does not seem to be an easy way to pinpoint the line in the code that blocked the event loop.

However, we can use our existing monitoring infrastructure to try to correlate event loop delays with ongoing / recent requests.

We can leverage the information stored in our overview cluster:

• On one hand, we are logging event loop delays on serverless.metrics-* indices.
• On the other hand, we are logging all requests to Kibana in our serverless-logging-*:logs-proxy* indices.

Thus, whenever we detect a substantial event loop delay on a given project, we can search the proxy logs and list the requests that were taking place around that time. If Kibana has been blocked for e.g. 10 seconds, a request must exist, which took at least 10 seconds to respond. Whilst it does not directly pinpoint the line in the code that caused the delay, it can constitute a good starting point to investigate and dispatch to the right team.

This is the goal of the newly introduced [Serverless] Event Loop Delays dashboard (see PR).

Also, in line with recent discussions, and with Rudolf's last comment, I am updating the kibana.stats.process.event_loop_delay.ms reported by Kibana on /api/status, changing it from mean to max.

[dgieselaar]

want to flag that we can already correlate event loop delay with requests via server.eluMonitor.enabled: true and server.eluMonitor.logging.enabled: false. It's logged and/or added to as a label to APM transactions. See https://github.com/elastic/kibana/blob/main/packages/core/http/core-http-server-internal/src/http_server.ts