diff --git a/.github/workflows/observability-apply-production.yml b/.github/workflows/observability-apply-production.yml index 0e61190f53c..c9e2a87a122 100644 --- a/.github/workflows/observability-apply-production.yml +++ b/.github/workflows/observability-apply-production.yml @@ -79,6 +79,19 @@ jobs: # CS-11107 bug — every evaluation failed with ResourceNotFoundException). WORKER_LOG_GROUP_NAME: ecs-boxel-worker-production WORKER_LOG_GROUP_ACCOUNT_ID: "120317779495" + # Realm-server availability alerts (realm-server-availability-group.json): + # the log group follows the deterministic `ecs-boxel-realm-server-` + # convention; the ALB and target-group dimension values carry generated + # hash suffixes, so they can't be derived from a naming convention — + # read them from: + # ALB: aws elbv2 describe-load-balancers --names boxel-realm-server-production + # (LoadBalancerArn's trailing `app//` segment) + # Target group: aws elbv2 describe-target-groups --load-balancer-arn + # (TargetGroupArn's trailing `targetgroup//` segment) + REALM_SERVER_LOG_GROUP_NAME: ecs-boxel-realm-server-production + REALM_SERVER_LOG_GROUP_ACCOUNT_ID: "120317779495" + REALM_SERVER_ALB_FULL_NAME: app/boxel-realm-server-production/e1d83dcf1a10d92f + REALM_SERVER_TARGET_GROUP_FULL_NAME: targetgroup/boxel-realm-server-production/f5582cefd78674e5 steps: - name: Refuse to apply from non-main branches diff --git a/.github/workflows/observability-apply-staging.yml b/.github/workflows/observability-apply-staging.yml index bc43979cb26..ee81a6bc9ea 100644 --- a/.github/workflows/observability-apply-staging.yml +++ b/.github/workflows/observability-apply-staging.yml @@ -63,6 +63,19 @@ jobs: # AWS_ROLE_ARN need to update together. WORKER_LOG_GROUP_NAME: ecs-boxel-worker-staging WORKER_LOG_GROUP_ACCOUNT_ID: "680542703984" + # Realm-server availability alerts (realm-server-availability-group.json): + # the log group follows the deterministic `ecs-boxel-realm-server-` + # convention; the ALB and target-group dimension values carry generated + # hash suffixes, so they can't be derived from a naming convention — + # read them from: + # ALB: aws elbv2 describe-load-balancers --names boxel-realm-server-staging + # (LoadBalancerArn's trailing `app//` segment) + # Target group: aws elbv2 describe-target-groups --load-balancer-arn + # (TargetGroupArn's trailing `targetgroup//` segment) + REALM_SERVER_LOG_GROUP_NAME: ecs-boxel-realm-server-staging + REALM_SERVER_LOG_GROUP_ACCOUNT_ID: "680542703984" + REALM_SERVER_ALB_FULL_NAME: app/boxel-realm-server-staging/f63ab9f02a6fba2a + REALM_SERVER_TARGET_GROUP_FULL_NAME: targetgroup/boxel-realm-server-staging/35ffa258763f010c steps: - name: Checkout diff --git a/packages/observability/README.md b/packages/observability/README.md index fffc7d01aa0..df5b9ce0b49 100644 --- a/packages/observability/README.md +++ b/packages/observability/README.md @@ -38,7 +38,8 @@ grafanactl/ dashboards/ # grafanactl push: dashboard JSON, organized by folder provisioning/ # mounted into Grafana at /etc/grafana/provisioning/ datasources/ # data sources (Loki, Postgres, CloudWatch, Prometheus) - alerting/ # alert rule groups, contact points, notification policies + alerting/ # alert rule groups (no contact points / notification + # policies live here — routing uses Grafana's defaults) local-only/ # local-dev overrides — bind-mounted file-by-file over # `datasources/`. apply-datasources.sh ignores this dir. collectors/ diff --git a/packages/observability/provisioning/alerting/realm-server-availability-group.json b/packages/observability/provisioning/alerting/realm-server-availability-group.json new file mode 100644 index 00000000000..cac2a18cb93 --- /dev/null +++ b/packages/observability/provisioning/alerting/realm-server-availability-group.json @@ -0,0 +1,599 @@ +{ + "apiVersion": 1, + "groups": [ + { + "orgId": 1, + "name": "realm-server-availability-group", + "folder": "defd2d156sav4d", + "interval": "60s", + "rules": [ + { + "uid": "rs-no-healthy-targets", + "orgID": 1, + "folderUID": "defd2d156sav4d", + "ruleGroup": "realm-server-availability-group", + "title": "Realm Server No Healthy Targets", + "condition": "B", + "annotations": { + "summary": "The realm-server ALB target group had zero healthy targets at least once in the last 5 minutes — clients get 503s and the service is effectively down. This is the primary availability signal: unlike the 5xx-surge rule it reads HealthyHostCount, which CloudWatch publishes continuously, so its noDataState is Alerting — a stale or mistyped REALM_SERVER_TARGET_GROUP_FULL_NAME yields an empty result rather than an error, which trips this rule loudly instead of silently resolving OK. Both replicas hitting the V8 heap limit within a minute is the incident signature; check the OOM and heap alerts in this group." + }, + "data": [ + { + "refId": "A", + "queryType": "", + "relativeTimeRange": { + "from": 300, + "to": 0 + }, + "datasourceUid": "cef5x9o3yzawwf", + "model": { + "datasource": { + "type": "cloudwatch", + "uid": "cef5x9o3yzawwf" + }, + "dimensions": { + "LoadBalancer": "${REALM_SERVER_ALB_FULL_NAME}", + "TargetGroup": "${REALM_SERVER_TARGET_GROUP_FULL_NAME}" + }, + "expression": "", + "id": "", + "intervalMs": 1000, + "label": "", + "matchExact": true, + "maxDataPoints": 43200, + "metricEditorMode": 0, + "metricName": "HealthyHostCount", + "metricQueryType": 0, + "namespace": "AWS/ApplicationELB", + "period": "60", + "queryMode": "Metrics", + "refId": "A", + "region": "default", + "sqlExpression": "", + "statistic": "Minimum" + } + }, + { + "refId": "C", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "A", + "intervalMs": 1000, + "maxDataPoints": 43200, + "reducer": "min", + "refId": "C", + "type": "reduce" + } + }, + { + "refId": "B", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "conditions": [ + { + "evaluator": { + "params": [1, 0], + "type": "lt" + }, + "operator": { + "type": "and" + }, + "query": { + "params": [] + }, + "reducer": { + "params": [], + "type": "avg" + }, + "type": "query" + } + ], + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "C", + "intervalMs": 1000, + "maxDataPoints": 43200, + "refId": "B", + "type": "threshold" + } + } + ], + "noDataState": "Alerting", + "execErrState": "Alerting", + "for": "0s", + "isPaused": false, + "notification_settings": null + }, + { + "uid": "rs-alb-5xx-surge", + "orgID": 1, + "folderUID": "defd2d156sav4d", + "ruleGroup": "realm-server-availability-group", + "title": "Realm Server ALB 5xx Surge", + "condition": "B", + "annotations": { + "summary": "The realm-server ALB returned ELB-generated 5xx at more than 50/minute at least once in the last 5 minutes. ELB-generated 5xx (as opposed to target 5xx) means the ALB could not get a valid response from any target — targets crashed, hung, or deregistered. Check ECS task health, the no-healthy-targets alert, and the heap/OOM alerts in this group." + }, + "data": [ + { + "refId": "A", + "queryType": "", + "relativeTimeRange": { + "from": 300, + "to": 0 + }, + "datasourceUid": "cef5x9o3yzawwf", + "model": { + "datasource": { + "type": "cloudwatch", + "uid": "cef5x9o3yzawwf" + }, + "dimensions": { + "LoadBalancer": "${REALM_SERVER_ALB_FULL_NAME}" + }, + "expression": "", + "id": "", + "intervalMs": 1000, + "label": "", + "matchExact": true, + "maxDataPoints": 43200, + "metricEditorMode": 0, + "metricName": "HTTPCode_ELB_5XX_Count", + "metricQueryType": 0, + "namespace": "AWS/ApplicationELB", + "period": "60", + "queryMode": "Metrics", + "refId": "A", + "region": "default", + "sqlExpression": "", + "statistic": "Sum" + } + }, + { + "refId": "C", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "A", + "intervalMs": 1000, + "maxDataPoints": 43200, + "reducer": "max", + "refId": "C", + "type": "reduce" + } + }, + { + "refId": "B", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "conditions": [ + { + "evaluator": { + "params": [50, 0], + "type": "gt" + }, + "operator": { + "type": "and" + }, + "query": { + "params": [] + }, + "reducer": { + "params": [], + "type": "avg" + }, + "type": "query" + } + ], + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "C", + "intervalMs": 1000, + "maxDataPoints": 43200, + "refId": "B", + "type": "threshold" + } + } + ], + "noDataState": "OK", + "execErrState": "Alerting", + "for": "0s", + "isPaused": false, + "notification_settings": null + }, + { + "uid": "rs-oom-crash", + "orgID": 1, + "folderUID": "defd2d156sav4d", + "ruleGroup": "realm-server-availability-group", + "title": "Realm Server OOM Crash", + "condition": "B", + "annotations": { + "summary": "A realm-server process hit the V8 heap limit and died (FATAL ERROR: Reached heap limit / JavaScript heap out of memory). ECS will replace the task; if the surviving replica absorbs the failed-over load it can OOM too, taking the service down. Identify what drove heap growth (usually a _search / _federated-search storm — check inFlightSearch in the health line, which counts both routes)." + }, + "data": [ + { + "refId": "A", + "queryType": "", + "relativeTimeRange": { + "from": 600, + "to": 0 + }, + "datasourceUid": "cef5x9o3yzawwf", + "model": { + "datasource": { + "type": "cloudwatch", + "uid": "cef5x9o3yzawwf" + }, + "dimensions": {}, + "expression": "filter @message like /Reached heap limit/ or @message like /JavaScript heap out of memory/\n| stats count() as oomCount by bin(5m)", + "id": "", + "intervalMs": 1000, + "label": "", + "logGroups": [ + { + "accountId": "${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}", + "arn": "arn:aws:logs:us-east-1:${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}:log-group:${REALM_SERVER_LOG_GROUP_NAME}", + "name": "${REALM_SERVER_LOG_GROUP_NAME}" + } + ], + "matchExact": true, + "maxDataPoints": 43200, + "metricEditorMode": 0, + "metricName": "", + "metricQueryType": 0, + "namespace": "", + "period": "", + "queryMode": "Logs", + "refId": "A", + "region": "default", + "sqlExpression": "", + "statistic": "Average" + } + }, + { + "refId": "C", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "A", + "intervalMs": 1000, + "maxDataPoints": 43200, + "reducer": "max", + "refId": "C", + "type": "reduce" + } + }, + { + "refId": "B", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "conditions": [ + { + "evaluator": { + "params": [0, 0], + "type": "gt" + }, + "operator": { + "type": "and" + }, + "query": { + "params": [] + }, + "reducer": { + "params": [], + "type": "avg" + }, + "type": "query" + } + ], + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "C", + "intervalMs": 1000, + "maxDataPoints": 43200, + "refId": "B", + "type": "threshold" + } + } + ], + "noDataState": "OK", + "execErrState": "Alerting", + "for": "0s", + "isPaused": false, + "notification_settings": null + }, + { + "uid": "rs-heap-near-limit", + "orgID": 1, + "folderUID": "defd2d156sav4d", + "ruleGroup": "realm-server-availability-group", + "title": "Realm Server Heap Near Limit", + "condition": "B", + "annotations": { + "summary": "A realm-server process's JS heap exceeded 80% of its V8 heap limit at least once in the last 5 minutes (at the limit the process dies and drops every in-flight request). Sourced from the periodic health line as a heapUsedMB/heapLimitMB ratio, so it holds across ECS task resizes and Node upgrades rather than assuming a fixed ~2GB limit. Usually driven by concurrent _search / _federated-search load; see the search-saturation alert." + }, + "data": [ + { + "refId": "A", + "queryType": "", + "relativeTimeRange": { + "from": 300, + "to": 0 + }, + "datasourceUid": "cef5x9o3yzawwf", + "model": { + "datasource": { + "type": "cloudwatch", + "uid": "cef5x9o3yzawwf" + }, + "dimensions": {}, + "expression": "filter @message like /heapUsedMB=/\n| parse @message /heapUsedMB=(?\\d+)/\n| parse @message /heapLimitMB=(?\\d+)/\n| fields used / limit * 100 as heapPct\n| stats max(heapPct) as maxHeapPct by bin(1m)", + "id": "", + "intervalMs": 1000, + "label": "", + "logGroups": [ + { + "accountId": "${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}", + "arn": "arn:aws:logs:us-east-1:${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}:log-group:${REALM_SERVER_LOG_GROUP_NAME}", + "name": "${REALM_SERVER_LOG_GROUP_NAME}" + } + ], + "matchExact": true, + "maxDataPoints": 43200, + "metricEditorMode": 0, + "metricName": "", + "metricQueryType": 0, + "namespace": "", + "period": "", + "queryMode": "Logs", + "refId": "A", + "region": "default", + "sqlExpression": "", + "statistic": "Average" + } + }, + { + "refId": "C", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "A", + "intervalMs": 1000, + "maxDataPoints": 43200, + "reducer": "max", + "refId": "C", + "type": "reduce" + } + }, + { + "refId": "B", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "conditions": [ + { + "evaluator": { + "params": [80, 0], + "type": "gt" + }, + "operator": { + "type": "and" + }, + "query": { + "params": [] + }, + "reducer": { + "params": [], + "type": "avg" + }, + "type": "query" + } + ], + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "C", + "intervalMs": 1000, + "maxDataPoints": 43200, + "refId": "B", + "type": "threshold" + } + } + ], + "noDataState": "OK", + "execErrState": "Alerting", + "for": "0s", + "isPaused": false, + "notification_settings": null + }, + { + "uid": "rs-search-saturation", + "orgID": 1, + "folderUID": "defd2d156sav4d", + "ruleGroup": "realm-server-availability-group", + "title": "Realm Server Search Saturation", + "condition": "B", + "annotations": { + "summary": "A realm-server process reached 15+ concurrent _search / _federated-search requests at least once in the last 5 minutes (baseline is single digits). Sourced from the periodic health line (inFlightSearch=N, which counts both routes — including the in-render _search round-trips prerender issues). Concurrent search load drives heap growth toward OOM — this is the early-warning signal; find which client/realm is issuing the searches." + }, + "data": [ + { + "refId": "A", + "queryType": "", + "relativeTimeRange": { + "from": 300, + "to": 0 + }, + "datasourceUid": "cef5x9o3yzawwf", + "model": { + "datasource": { + "type": "cloudwatch", + "uid": "cef5x9o3yzawwf" + }, + "dimensions": {}, + "expression": "filter @message like /inFlightSearch=/\n| parse @message /inFlightSearch=(?\\d+)/\n| stats max(n) as maxInFlight by bin(1m)", + "id": "", + "intervalMs": 1000, + "label": "", + "logGroups": [ + { + "accountId": "${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}", + "arn": "arn:aws:logs:us-east-1:${REALM_SERVER_LOG_GROUP_ACCOUNT_ID}:log-group:${REALM_SERVER_LOG_GROUP_NAME}", + "name": "${REALM_SERVER_LOG_GROUP_NAME}" + } + ], + "matchExact": true, + "maxDataPoints": 43200, + "metricEditorMode": 0, + "metricName": "", + "metricQueryType": 0, + "namespace": "", + "period": "", + "queryMode": "Logs", + "refId": "A", + "region": "default", + "sqlExpression": "", + "statistic": "Average" + } + }, + { + "refId": "C", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "A", + "intervalMs": 1000, + "maxDataPoints": 43200, + "reducer": "max", + "refId": "C", + "type": "reduce" + } + }, + { + "refId": "B", + "queryType": "", + "relativeTimeRange": { + "from": 0, + "to": 0 + }, + "datasourceUid": "__expr__", + "model": { + "conditions": [ + { + "evaluator": { + "params": [15, 0], + "type": "gt" + }, + "operator": { + "type": "and" + }, + "query": { + "params": [] + }, + "reducer": { + "params": [], + "type": "avg" + }, + "type": "query" + } + ], + "datasource": { + "name": "Expression", + "type": "__expr__", + "uid": "__expr__" + }, + "expression": "C", + "intervalMs": 1000, + "maxDataPoints": 43200, + "refId": "B", + "type": "threshold" + } + } + ], + "noDataState": "OK", + "execErrState": "Alerting", + "for": "0s", + "isPaused": false, + "notification_settings": null + } + ] + } + ] +} diff --git a/packages/realm-server/health-sampler.ts b/packages/realm-server/health-sampler.ts index 2f685162f16..e24ae7cef0b 100644 --- a/packages/realm-server/health-sampler.ts +++ b/packages/realm-server/health-sampler.ts @@ -1,10 +1,13 @@ import { monitorEventLoopDelay, type IntervalHistogram } from 'node:perf_hooks'; import { logger } from '@cardstack/runtime-common'; import { getSearchInFlight } from './search-inflight.ts'; +import { + heapTelemetry, + formatHeapTelemetry, +} from './prerender/heap-telemetry.ts'; -// Periodically samples the realm-server process's event-loop health and -// in-flight search count, logging a `realm:health` line whenever there's a -// saturation signal worth capturing. +// Periodically samples the realm-server process's event-loop health, in-flight +// search count, and heap usage, emitting a `realm:health` line every interval. // // Why: during a from-scratch index, prerendered cards block in // `waiting-stability` on `_search` round-trips that the realm-server is slow @@ -14,23 +17,25 @@ import { getSearchInFlight } from './search-inflight.ts'; // concurrent searches) so requests sit unserviced. Event-loop lag rising in // lockstep with `inFlightSearch` is the fingerprint of exactly that. // +// The line is emitted unconditionally rather than only inside saturation +// windows: heap growth toward the OOM limit is exactly the thing an alert has +// to catch *before* a storm, so the heap number has to be present on a calm, +// idle-loop process too. A quiet-when-healthy line makes a surviving replica +// sitting at a high retained heap indistinguishable from a healthy one — the +// blind spot the availability alerts exist to close. +// // `monitorEventLoopDelay` measures the delay between when a timer was // scheduled and when it actually fired — i.e. how long synchronous work kept // the loop from turning. Values are nanoseconds. export interface HealthSamplerOptions { - // How often to sample + maybe log. Defaults to 5s. + // How often to sample + log. Defaults to 5s. intervalMs?: number; - // Only log when peak loop lag in the window exceeds this (or a search is - // in flight). Keeps the line quiet on an idle/healthy server. Defaults to - // 200ms. - lagThresholdMs?: number; } export function startHealthSampler( opts: HealthSamplerOptions = {}, ): () => void { let intervalMs = opts.intervalMs ?? 5000; - let lagThresholdMs = opts.lagThresholdMs ?? 200; // Created here (not at module load) to avoid racing the circular import // that installs the logger factory; startup calls this well after boot. let log = logger('realm:health'); @@ -44,15 +49,15 @@ export function startHealthSampler( let p99LagMs = toMs(histogram.percentile(99)); histogram.reset(); let inFlightSearch = getSearchInFlight(); - // Stay silent when the loop is healthy and nothing is in flight — only - // the saturation windows are interesting. - if (maxLagMs < lagThresholdMs && inFlightSearch === 0) { - return; - } - let heapMB = Math.round(process.memoryUsage().heapUsed / (1024 * 1024)); + // Reuse the prerender heap-telemetry helpers so the realm-server health + // line carries the same `heapUsedMB=… heapLimitMB=…` fields (one spelling + // of the quantity, and the effective V8 limit read from the running + // process rather than assumed from the task definition). Alerts threshold + // on the used/limit ratio, which survives a task resize or a Node bump. + let heap = heapTelemetry(); log.info( `eventLoopLagMs(mean/p99/max)=${meanLagMs.toFixed(0)}/${p99LagMs.toFixed(0)}/${maxLagMs.toFixed(0)} ` + - `inFlightSearch=${inFlightSearch} heapMB=${heapMB}`, + `inFlightSearch=${inFlightSearch} ${formatHeapTelemetry(heap)}`, ); }, intervalMs); // Don't keep the process alive solely for sampling. diff --git a/packages/realm-server/main.ts b/packages/realm-server/main.ts index a07e3eed2a9..2209563918c 100644 --- a/packages/realm-server/main.ts +++ b/packages/realm-server/main.ts @@ -470,10 +470,11 @@ const reportHostShellToManager = async () => { // `jobs_finished` NOTIFY evicts the same entries the handlers populate. let searchCache = new JobScopedSearchCache(dbAdapter); searchCache.startJanitor(); - // Periodic event-loop-lag + in-flight-search sampler. Emits a - // `realm:health` line only during saturation windows, so a stalled - // `_search` can be checked against whether the process's event loop was - // starved at the time. + // Periodic event-loop-lag + in-flight-search + heap sampler. Emits a + // `realm:health` line every interval, so a stalled `_search` can be checked + // against whether the process's event loop was starved at the time, and heap + // growth toward the OOM limit is visible (and alertable) on a calm process + // before a search storm — not only inside saturation windows. let stopHealthSampler = startHealthSampler(); let reconciler: RealmRegistryReconciler | undefined; let fileChangesListener: RealmFileChangesListener | undefined;