[Infrastructure UI][Rules] Add logging to Metric Threshold Rule

[simianhacker]

Summary

This PR adds logging for the execution time (debug) along with the Elasticsearch request/responses (trace) to the Metric Threshold Rule.

To enable the logging for the Metric Threshold rule, add the following snippet to your config/kibana.dev.yml:

logging.loggers:
  - name: plugins.infra.metricThresholdRule
    level: trace

Example Log Format

[2022-05-17T09:58:20.209-06:00][TRACE][plugins.infra.metricThresholdRule] [AlertId: cbf86ed0-d5f6-11ec-8e5e-efda79ee6822][ExecutionId: 33745d86-4f21-4cf2-805a-4ca2b9528805] Request: {"index":"metrics-*,metricbeat-*","allow_no_indices":true,"ignore_unavailable":true,"body":{"track_total_hits":true,"query":{"bool":{"filter":[{"range":{"@timestamp":{"gte":"2022-05-17T15:56:17.079Z","lte":"2022-05-17T15:58:20.084Z"}}},{"exists":{"field":"system.cpu.total.norm.pct"}}]}},"size":0,"aggs":{"groupings":{"composite":{"size":10000,"sources":[{"groupBy0":{"terms":{"field":"host.name"}}}],"after":{"groupBy0":"host-4"}},"aggs":{"currentPeriod":{"filter":{"range":{"@timestamp":{"gte":"2022-05-17T15:57:20.084Z","lte":"2022-05-17T15:58:20.084Z"}}},"aggs":{"aggregatedValue":{"avg":{"field":"system.cpu.total.norm.pct"}}}},"shouldWarn":{"bucket_script":{"buckets_path":{},"script":"0"}},"shouldTrigger":{"bucket_script":{"buckets_path":{"value":"currentPeriod>aggregatedValue"},"script":"params.value > 0.01 ? 1 : 0"}},"lastPeriod":{"filter":{"range":{"@timestamp":{"gte":"2022-05-17T15:56:17.079Z","lte":"2022-05-17T15:57:17.079Z"}}}},"missingGroup":{"bucket_script":{"buckets_path":{"lastPeriod":"lastPeriod>_count","currentPeriod":"currentPeriod>_count"},"script":"params.lastPeriod > 0 && params.currentPeriod < 1 ? 1 : 0"}},"newOrRecoveredGroup":{"bucket_script":{"buckets_path":{"lastPeriod":"lastPeriod>_count","currentPeriod":"currentPeriod>_count"},"script":"params.lastPeriod < 1 && params.currentPeriod > 0 ? 1 : 0"}},"evaluation":{"bucket_selector":{"buckets_path":{"shouldWarn":"shouldWarn","shouldTrigger":"shouldTrigger","missingGroup":"missingGroup","newOrRecoveredGroup":"newOrRecoveredGroup"},"script":"(params.missingGroup != null && params.missingGroup > 0) || (params.shouldWarn != null && params.shouldWarn > 0) || (params.shouldTrigger != null && params.shouldTrigger > 0) || (params.newOrRecoveredGroup != null && params.newOrRecoveredGroup > 0)"}}}}}}}
[2022-05-17T09:58:20.211-06:00][TRACE][plugins.infra.metricThresholdRule] [AlertId: cbf86ed0-d5f6-11ec-8e5e-efda79ee6822][ExecutionId: 33745d86-4f21-4cf2-805a-4ca2b9528805] Response: {"took":0,"timed_out":false,"_shards":{"total":1,"successful":1,"skipped":0,"failed":0},"hits":{"total":{"value":60,"relation":"eq"},"max_score":null,"hits":[]},"aggregations":{"groupings":{"buckets":[]}}}
[2022-05-17T09:58:20.213-06:00][DEBUG][plugins.infra.metricThresholdRule] [AlertId: cbf86ed0-d5f6-11ec-8e5e-efda79ee6822][ExecutionId: 33745d86-4f21-4cf2-805a-4ca2b9528805] Scheduled 5 actions in 12ms

Checklist

• Unit or functional tests were updated or added to match the most common scenarios

[kibana-ci]

💚 Build Succeeded

• Buildkite Build
• Commit: d537560
• Storybooks Preview
• Webpack Bundle Analyzer

Metrics [docs]

✅ unchanged

History

• 💔 Build #45449 failed 5b274a3

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream

[elasticmachine]

Pinging @elastic/infra-monitoring-ui (Team:Infra Monitoring UI)

[matschaffer]

Got some logs LGTM

[2022-05-18T10:32:46.473+09:00][TRACE][plugins.infra.metricThresholdRule] [AlertId: 69402c20-d64a-11ec-840b-fdd156179a03][ExecutionId: 8005ed8e-8c4f-46df-a4e6-cf9e8c65e14e] Request: {"index":"metrics-*,metricbeat-*","allow_no_indices":true,"ignore_unavailable":true,"body":{"track_total_hits":true,"query":{"bool":{"filter":[{"range":{"@timestamp":{"gte":"2022-05-18T01:31:46.339Z","lte":"2022-05-18T01:32:46.339Z"}}},{"exists":{"field":"system.cpu.total.pct"}}]}},"size":0,"aggs":{"all":{"filters":{"filters":{"all":{"match_all":{}}}},"aggs":{"currentPeriod":{"filter":{"range":{"@timestamp":{"gte":"2022-05-18T01:31:46.339Z","lte":"2022-05-18T01:32:46.339Z"}}},"aggs":{"aggregatedValue":{"avg":{"field":"system.cpu.total.pct"}}}},"shouldWarn":{"bucket_script":{"buckets_path":{},"script":"0"}},"shouldTrigger":{"bucket_script":{"buckets_path":{"value":"currentPeriod>aggregatedValue"},"script":"params.value > 0.3 ? 1 : 0"}}}}}}}
[2022-05-18T10:32:46.485+09:00][TRACE][plugins.infra.metricThresholdRule] [AlertId: 69402c20-d64a-11ec-840b-fdd156179a03][ExecutionId: 8005ed8e-8c4f-46df-a4e6-cf9e8c65e14e] Response: {"took":8,"timed_out":false,"_shards":{"total":1,"successful":1,"skipped":0,"failed":0},"hits":{"total":{"value":6,"relation":"eq"},"max_score":null,"hits":[]},"aggregations":{"all":{"buckets":{"all":{"doc_count":6,"currentPeriod":{"doc_count":6,"aggregatedValue":{"value":0.11966666666666666}},"shouldWarn":{"value":0},"shouldTrigger":{"value":0}}}}}}

[matschaffer]

I've been trying to avoid sinon in favor of jest.fn in my tests but looks like this isn't really net-new code so LGTM.

[matschaffer]

This makes me think about APM tracing :) Guess logging is probably a more critical base feature though.