alerting: base web/worker liveness on the app heartbeat, not container stdout (#94)
All checks were successful
shell-lint / shellcheck (push) Successful in 7s
secrets-guard / encrypted (push) Successful in 5s
Validate observability stack / validate (push) Successful in 12s
secrets-guard / encrypted (pull_request) Successful in 7s
shell-lint / shellcheck (pull_request) Successful in 8s
PR build (required check) / build-backend (pull_request) Has been skipped
PR build (required check) / validate-observability (pull_request) Successful in 18s
PR build (required check) / changes (pull_request) Successful in 8s
PR build (required check) / build-frontend (pull_request) Has been skipped
PR build (required check) / gate (pull_request) Successful in 2s

This commit is contained in:
emi 2026-07-25 17:51:42 +00:00
parent d4a00099f2
commit 1a56a63800

View file

@ -400,6 +400,24 @@ groups:
# dev is deliberately excluded: the LAN box had zero heartbeats for the # dev is deliberately excluded: the LAN box had zero heartbeats for the
# first 10.5h of the backtest window because it was simply off. Alerting # first 10.5h of the backtest window because it was simply off. Alerting
# on dev would mean an alert that is firing more often than not. # on dev would mean an alert that is firing more often than not.
#
# MUST stay filtered to daemon="subscription-notifier". The selector was
# originally bare `tag="heartbeat"`, which was unambiguous while the
# notifier thread was the only thing that ever beat. It stopped being
# unambiguous on 2026-07-25T17:24Z, when web/app.py's _start_heartbeat
# shipped: every uvicorn process in every replica now beats every 300s
# under the same tag, tagged daemon=web / daemon=worker. Measured
# immediately after that deploy, a 20m window held 16 web beats and 4
# worker beats against 2 notifier beats — so the bare selector clears the
# `< 1` threshold on web traffic alone and can no longer observe the
# notifier at all.
#
# That matters because this rule had just caught a real 17.5h outage
# (notifier silent 2026-07-24T23:49Z -> 2026-07-25T17:25Z, zero
# subscription notifications delivered). Left bare, it would have gone
# quiet on the next occurrence instead of paging. `daemon` is a JSON field
# and not a stream label, hence the `| json |` parse rather than a label
# matcher.
- uid: tg_notifier_heartbeat_prod - uid: tg_notifier_heartbeat_prod
title: NotifierHeartbeatMissingProd title: NotifierHeartbeatMissingProd
condition: C condition: C
@ -427,7 +445,7 @@ groups:
model: model:
refId: A refId: A
datasource: { type: loki, uid: loki } datasource: { type: loki, uid: loki }
expr: 'sum(count_over_time({job="app-json", tag="heartbeat", host="prod"} [20m])) or vector(0)' expr: 'sum(count_over_time({job="app-json", tag="heartbeat", host="prod"} | json | daemon="subscription-notifier" [20m])) or vector(0)'
queryType: instant queryType: instant
editorMode: code editorMode: code
intervalMs: 1000 intervalMs: 1000
@ -480,7 +498,7 @@ groups:
model: model:
refId: A refId: A
datasource: { type: loki, uid: loki } datasource: { type: loki, uid: loki }
expr: 'sum(count_over_time({job="app-json", tag="heartbeat", host="beta"} [20m])) or vector(0)' expr: 'sum(count_over_time({job="app-json", tag="heartbeat", host="beta"} | json | daemon="subscription-notifier" [20m])) or vector(0)'
queryType: instant queryType: instant
editorMode: code editorMode: code
intervalMs: 1000 intervalMs: 1000
@ -506,16 +524,31 @@ groups:
- evaluator: { type: lt, params: [1] } - evaluator: { type: lt, params: [1] }
# =========================================================================== # ===========================================================================
# Per-container liveness, inferred from log volume. The fleet collects no # Per-service liveness. The fleet collects no container metrics, so liveness
# container metrics, so "did this service stop producing any output at all" is # has to be inferred from "is this thing still producing output at all". Two
# the only death certificate available — and it turns out to be a good one, # different sources are used here, and picking the wrong one is how this group
# because every service below logs on a floor that never approaches zero. # generated a day of false pages:
# #
# Caveat worth knowing before you trust these: a container can be running and # * db and frontend infer it from CONTAINER LOG VOLUME. Valid for these two:
# logging while its lines never reach Loki, if the node's Alloy agent stops # both log to stdout on a floor that never approaches zero (db a metronomic
# tailing it. That is a real observed failure on prod (see README). These # 54-69 lines/2h, frontend ~66/30m), and prod's Alloy ships both.
# rules cannot tell the two apart — they say "no logs", which is the honest #
# claim. Either way something needs looking at. # * web and worker infer it from the APP'S OWN HEARTBEAT (tag=heartbeat in
# the app-json file source, filtered by the daemon field). Container log
# volume is NOT a valid liveness signal for either: web's request logging
# moved off stdout onto app-json, and worker's stdout is dropped outright
# by a rule in prod's alloy config. Both containers can be perfectly
# healthy while their docker streams sit at exactly zero forever.
#
# Before adding a container-log-silence rule for a new service, confirm the
# service actually logs to stdout AND that prod's discovery.relabel "containers"
# block does not drop it. A rule against a dropped stream is unsatisfiable and
# will page forever.
#
# Caveat that still applies to the db/frontend rules: a container can be
# running and logging while its lines never reach Loki, if the node's Alloy
# agent stops tailing it. Those rules cannot tell the two apart — they say
# "no logs", which is the honest claim. Either way something needs looking at.
# =========================================================================== # ===========================================================================
- orgId: 1 - orgId: 1
name: prod-services name: prod-services
@ -524,24 +557,43 @@ groups:
rules: rules:
# -- 8 ----------------------------------------------------------------- # -- 8 -----------------------------------------------------------------
# DATA: 15-minute windows over 24h ranged 54 -> 954 lines. The minimum, 54, # Web-tier liveness, from the app's own heartbeat rather than container
# occurred during the outage; the quietest healthy window was ~150. A # stdout.
# 30-minute window has never been below ~110. Zero means the container is #
# gone. This is the app itself, so it pages. # This rule used to count `{job="docker", container=~"thermograph_web.+"}`
# over 30m against a measured floor of ~110 lines. That floor was real when
# it was written (the backtest saw 3.8k-10.5k lines per 6h), but the app
# moved its request logging off stdout onto the app-json file source, and
# from 2026-07-25T00:02Z a web container emits ~15 uvicorn banner lines for
# its entire lifetime and nothing after. The old rule then sat firing
# permanently on a perfectly healthy tier, clearing only for the few
# minutes after each deploy or autoscale event produced fresh banners —
# 20+ pages in a day, every one of them false. See web/app.py's
# _start_heartbeat docstring, which states outright that stdout silence
# cannot distinguish a live web process from a dead one and that this
# heartbeat is the signal to alert on instead.
#
# DATA: _start_heartbeat beats every 300s from every uvicorn process in
# every replica, unguarded by the leader election, so a 4-process replica
# yields ~16 beats per 20m (measured: exactly 16). Zero over 20m means no
# web process is alive anywhere. This is the app itself, so it pages.
- uid: tg_prod_web_silent - uid: tg_prod_web_silent
title: ProdWebContainerSilent title: ProdWebHeartbeatMissing
condition: C condition: C
for: 5m for: 5m
noDataState: OK noDataState: OK
execErrState: OK execErrState: OK
annotations: annotations:
summary: 'prod: thermograph_web has logged nothing for 30 minutes' summary: 'prod: no web heartbeat for 20 minutes'
description: >- description: >-
The main app container has produced zero log lines in 30 minutes. No thermograph_web process on prod has emitted a liveness heartbeat
Healthy floor is ~110 lines per 30m and it never dipped below 54 even in 20 minutes. Every uvicorn process beats every 5 minutes
mid-outage, so this is a container that is gone, wedged, or no longer independently of the notifier leader election, so a healthy 4-process
being tailed by prod's Alloy agent. Run `docker service ps replica produces ~16 beats per window — zero means no web process is
thermograph_web` on prod. alive anywhere, not merely quiet. Run `docker service ps
thermograph_web` on prod. Note this is the app's own heartbeat, not
container stdout: web's stdout is silent by design and is not a
liveness signal.
labels: labels:
severity: critical severity: critical
host: prod host: prod
@ -549,12 +601,12 @@ groups:
isPaused: false isPaused: false
data: data:
- refId: A - refId: A
relativeTimeRange: { from: 1800, to: 0 } relativeTimeRange: { from: 1200, to: 0 }
datasourceUid: loki datasourceUid: loki
model: model:
refId: A refId: A
datasource: { type: loki, uid: loki } datasource: { type: loki, uid: loki }
expr: 'sum(count_over_time({job="docker", host="prod", container=~"thermograph_web.+"} [30m])) or vector(0)' expr: 'sum(count_over_time({job="app-json", host="prod", tag="heartbeat"} | json | daemon="web" [20m])) or vector(0)'
queryType: instant queryType: instant
editorMode: code editorMode: code
intervalMs: 1000 intervalMs: 1000
@ -689,42 +741,50 @@ groups:
- evaluator: { type: lt, params: [1] } - evaluator: { type: lt, params: [1] }
# -- 11 ---------------------------------------------------------------- # -- 11 ----------------------------------------------------------------
# DATA: a dead-steady 121 lines/hour (its own healthcheck polling) for the # Worker liveness, from the app's own heartbeat rather than container
# first 14h of the backtest, then nothing at all. # stdout.
# #
# HEADS UP: THIS RULE WILL BE FIRING THE MOMENT YOU DEPLOY IT, and it is # The previous rule counted `{job="docker", container=~"thermograph_worker.+"}`
# right to. As of 2026-07-24 19:45Z the prod worker container is running # and was UNSATISFIABLE BY CONSTRUCTION — it could never return anything but
# and healthy and is writing ~19 lines per 10 minutes to its own docker # zero, no matter how healthy the worker was. prod's Alloy config drops that
# log — but not one of those lines has reached Loki since 04:43Z. Prod's # container on purpose, in discovery.relabel "containers":
# Alloy agent stopped tailing the container when Swarm replaced the task.
# Nobody knew, because nothing was watching. See README "Known gaps".
# #
# WHY THIS IS A WARNING AND NotifierHeartbeatMissingProd IS CRITICAL: the # regex = "(alloy|autoscaler|thermograph-test_.*|thermograph-lb|thermograph_worker).*"
# two draw on *different* Alloy sources — this one on loki.source.docker # action = "drop"
# (the container's stdout), the heartbeat on loki.source.file tailing #
# /applogs. That independence is the diagnostic. Right now prod's # with the stated reasoning that worker stdout was 100% /healthz poll noise
# heartbeats are arriving in every single 20-minute window while its # and the app's own access/*.jsonl is a strict superset of it. So the stream
# worker docker stream has been empty for 14 hours, which localises the # this rule queried is discarded at the agent and never reaches Loki.
# fault to Alloy's docker tail rather than to the worker: the process is #
# doing its job, we just cannot see it breathe. Both rules firing together # The old comment here read the resulting permanent zero as "Alloy stopped
# means the worker really is down. # tailing the container after Swarm replaced the task" and pointed the
# runbook at restarting alloy-alloy-1. That diagnosis was wrong, and the
# fix it recommended could not have worked: a restarted Alloy re-reads the
# same config and drops the same container again. The rule fired
# continuously from 2026-07-24T21:05Z with no underlying fault.
#
# DATA: _start_heartbeat beats every 300s from the worker process
# (measured: exactly 4 per 20m). Unlike the notifier below it is not gated
# on the leader election, so it reports the process being alive even when
# this worker is not the elected notifier — which is the distinction the
# old rule was trying and failing to draw.
- uid: tg_prod_worker_silent - uid: tg_prod_worker_silent
title: ProdWorkerContainerSilent title: ProdWorkerHeartbeatMissing
condition: C condition: C
for: 10m for: 10m
noDataState: OK noDataState: OK
execErrState: OK execErrState: OK
annotations: annotations:
summary: 'prod: thermograph_worker has logged nothing for 2 hours' summary: 'prod: no worker heartbeat for 20 minutes'
description: >- description: >-
The worker container has produced zero log lines in 2 hours against The thermograph_worker process on prod has not emitted a liveness
a healthy floor of ~242 per 2h. Two different faults look identical heartbeat in 20 minutes (healthy is ~4 per window, one every 5
here: the worker is actually dead, or prod's Alloy agent has stopped minutes). This beat is independent of the notifier leader election,
tailing it (a real, observed failure — Alloy can miss a container so it means the worker process itself is gone or wedged, not merely
after Swarm replaces the task). Check both: `docker service ps that it lost the election. Run `docker service ps thermograph_worker`
thermograph_worker` on prod, and whether `docker logs` on the live on prod. Do not look at the worker's container logs — prod's Alloy
container is producing lines that Loki does not have. Restarting config drops that stream deliberately, so it is always empty and is
alloy-alloy-1 on prod fixes the second case. not evidence of anything.
labels: labels:
severity: warning severity: warning
host: prod host: prod
@ -732,12 +792,12 @@ groups:
isPaused: false isPaused: false
data: data:
- refId: A - refId: A
relativeTimeRange: { from: 7200, to: 0 } relativeTimeRange: { from: 1200, to: 0 }
datasourceUid: loki datasourceUid: loki
model: model:
refId: A refId: A
datasource: { type: loki, uid: loki } datasource: { type: loki, uid: loki }
expr: 'sum(count_over_time({job="docker", host="prod", container=~"thermograph_worker.+"} [2h])) or vector(0)' expr: 'sum(count_over_time({job="app-json", host="prod", tag="heartbeat"} | json | daemon="worker" [20m])) or vector(0)'
queryType: instant queryType: instant
editorMode: code editorMode: code
intervalMs: 1000 intervalMs: 1000