alerting: base web/worker liveness on the app heartbeat, not container stdout #94

Merged

admin_emi merged 1 commit from fix/alerting-liveness-heartbeat into dev

2026-07-25 17:51:44 +00:00

admin_emi commented

2026-07-25 17:47:14 +00:00

Owner

What was firing, and whether it was real

Rule	Verdict
`ProdWorkerContainerSilent`	False — unsatisfiable by construction. Never had an underlying fault.
`ProdWebContainerSilent`	False since 2026-07-25T00:02Z. ~20 pages/day, all spurious.
`NotifierHeartbeatMissingProd`	REAL. Caught a 17.5h product outage.

1. `ProdWorkerContainerSilent` — could never have passed

It queried {job="docker", host="prod", container=~"thermograph_worker.+"}. prod's config.alloy drops that container deliberately:

regex  = "(alloy|autoscaler|thermograph-test_.*|thermograph-lb|thermograph_worker).*"
action = "drop"

The stream is discarded at the agent and never reaches Loki, so the rule returned 0 regardless of worker health — firing continuously since 2026-07-24T21:05Z. The rule's own comment diagnosed this as "Alloy stopped tailing the container after Swarm replaced the task" and told the operator to restart alloy-alloy-1; that could never have worked, since a restarted Alloy re-reads the same config and drops the same container again.

2. `ProdWebContainerSilent` — measured a floor that stopped existing

The ~110 lines/30m floor was real when written (Loki shows 3.8k–10.5k lines/6h for a week). The app then moved request logging off stdout onto the app-json file source. Measured on the live container: 15 stdout lines in a 17-hour lifetime, all uvicorn banners, 0 in the last 6h. Volume per 6h collapsed 3861 → 41 across the 00:02Z deploy.

It cleared only for the few minutes after each deploy/autoscale event emitted fresh banners — which is exactly the fire/resolve flapping in the channel.

web/app.py's _start_heartbeat docstring already says this outright: stdout silence "can't tell a live process from a dead one" for either role, and "this heartbeat is the signal observability actually alerts on instead." This PR does what that docstring asks.

3. `NotifierHeartbeatMissing{Prod,Beta}` — valid, and about to go blind

This rule was correct and it earned its keep: the subscription notifier went silent 2026-07-24T23:49Z → 2026-07-25T17:25Z (17.5h), no heartbeat-2026-07-25.jsonl was written at all, notify.pass stopped at the same instant, and zero subscription notifications were delivered while the site served 200s throughout. Not a monitoring artifact.

But the selector was a bare tag="heartbeat", which was unambiguous only while the notifier was the sole thing that beat. _start_heartbeat shipped at 2026-07-25T17:24Z and now every uvicorn process beats every 300s under that same tag. Measured right after: 16 web + 4 worker beats vs 2 notifier beats per 20m — the bare selector clears the < 1 threshold on web traffic alone and can no longer observe the notifier at all. The rule that had just caught a real outage would have sat silent through the next one. Now pinned to daemon="subscription-notifier".

Changes

tg_prod_web_silent → ProdWebHeartbeatMissing, reads daemon="web"
tg_prod_worker_silent → ProdWorkerHeartbeatMissing, reads daemon="worker"
tg_notifier_heartbeat_{prod,beta} pinned to daemon="subscription-notifier"
Group header rewritten to say which services may use container-log silence and which may not, so the next rule added here doesn't repeat the mistake

UIDs are unchanged, so this updates the existing rules rather than orphaning them and creating duplicates. db and frontend keep their container-log rules — both genuinely log to stdout (17,199 and 150 lines/6h) and neither is dropped by Alloy.

daemon is a JSON field, not a stream label, hence | json | rather than a label matcher.

Verification

All expressions run against live Loki (not just YAML-linted):

prod: web 16, worker 4, notifier 2 per 20m — all comfortably clear of the < 1 threshold
beta notifier: 37 consecutive 20m buckets over 12h, every one 1–2, never 0 — confirming the added filter won't introduce a new false page on beta, which also had a masking daemon="all" stream
YAML parses; 12 rules across 5 groups, unchanged count

Follow-up, not in this PR

The notifier outage has a root cause worth fixing separately. _should_run_notifier() is ROLE in (worker, all) and singleton.claim_leader(), evaluated once at startup and never retried. At the 00:02Z rolling restart the incoming worker lost the pg_try_advisory_lock election — most likely the outgoing worker's Postgres session still held it — logged "notifier": false, and then ran for 17.5 hours as a worker that would never notify anyone. It recovered only incidentally, when the PR #93 deploy restarted it and it happened to win the lock.

A lost election at boot should be retried rather than being a permanent, silent death sentence for the process.

Investigation of the "no logs" alerts flooding #ops-alerts. Three of the twelve prod rules were measuring streams that no longer say anything about the thing they claim to watch. **Prod was healthy throughout** — but one real product outage was hiding underneath the noise. ## What was firing, and whether it was real | Rule | Verdict | |---|---| | `ProdWorkerContainerSilent` | **False — unsatisfiable by construction.** Never had an underlying fault. | | `ProdWebContainerSilent` | **False since 2026-07-25T00:02Z.** ~20 pages/day, all spurious. | | `NotifierHeartbeatMissingProd` | **REAL.** Caught a 17.5h product outage. | ### 1. `ProdWorkerContainerSilent` — could never have passed It queried `{job="docker", host="prod", container=~"thermograph_worker.+"}`. prod's `config.alloy` drops that container deliberately: ``` regex = "(alloy|autoscaler|thermograph-test_.*|thermograph-lb|thermograph_worker).*" action = "drop" ``` The stream is discarded at the agent and never reaches Loki, so the rule returned `0` regardless of worker health — firing continuously since 2026-07-24T21:05Z. The rule's own comment diagnosed this as "Alloy stopped tailing the container after Swarm replaced the task" and told the operator to restart `alloy-alloy-1`; that could never have worked, since a restarted Alloy re-reads the same config and drops the same container again. ### 2. `ProdWebContainerSilent` — measured a floor that stopped existing The `~110 lines/30m` floor was real when written (Loki shows 3.8k–10.5k lines/6h for a week). The app then moved request logging off stdout onto the app-json file source. Measured on the live container: **15 stdout lines in a 17-hour lifetime**, all uvicorn banners, 0 in the last 6h. Volume per 6h collapsed `3861 → 41` across the 00:02Z deploy. It cleared only for the few minutes after each deploy/autoscale event emitted fresh banners — which is exactly the fire/resolve flapping in the channel. `web/app.py`'s `_start_heartbeat` docstring already says this outright: stdout silence *"can't tell a live process from a dead one"* for either role, and *"this heartbeat is the signal observability actually alerts on instead."* This PR does what that docstring asks. ### 3. `NotifierHeartbeatMissing{Prod,Beta}` — valid, and about to go blind This rule was correct and it earned its keep: the subscription notifier went silent **2026-07-24T23:49Z → 2026-07-25T17:25Z (17.5h)**, no `heartbeat-2026-07-25.jsonl` was written at all, `notify.pass` stopped at the same instant, and **zero subscription notifications were delivered** while the site served 200s throughout. Not a monitoring artifact. But the selector was a bare `tag="heartbeat"`, which was unambiguous only while the notifier was the sole thing that beat. `_start_heartbeat` shipped at 2026-07-25T17:24Z and now every uvicorn process beats every 300s under that same tag. Measured right after: **16 web + 4 worker beats vs 2 notifier beats per 20m** — the bare selector clears the `< 1` threshold on web traffic alone and can no longer observe the notifier at all. The rule that had just caught a real outage would have sat silent through the next one. Now pinned to `daemon="subscription-notifier"`. ## Changes - `tg_prod_web_silent` → `ProdWebHeartbeatMissing`, reads `daemon="web"` - `tg_prod_worker_silent` → `ProdWorkerHeartbeatMissing`, reads `daemon="worker"` - `tg_notifier_heartbeat_{prod,beta}` pinned to `daemon="subscription-notifier"` - Group header rewritten to say which services may use container-log silence and which may not, so the next rule added here doesn't repeat the mistake UIDs are unchanged, so this updates the existing rules rather than orphaning them and creating duplicates. `db` and `frontend` keep their container-log rules — both genuinely log to stdout (17,199 and 150 lines/6h) and neither is dropped by Alloy. `daemon` is a JSON field, not a stream label, hence `| json |` rather than a label matcher. ## Verification All expressions run against live Loki (not just YAML-linted): - prod: web **16**, worker **4**, notifier **2** per 20m — all comfortably clear of the `< 1` threshold - beta notifier: **37 consecutive 20m buckets over 12h, every one 1–2, never 0** — confirming the added filter won't introduce a new false page on beta, which also had a masking `daemon="all"` stream - YAML parses; 12 rules across 5 groups, unchanged count ## Follow-up, not in this PR The notifier outage has a root cause worth fixing separately. `_should_run_notifier()` is `ROLE in (worker, all) and singleton.claim_leader()`, evaluated **once at startup and never retried**. At the 00:02Z rolling restart the incoming worker lost the `pg_try_advisory_lock` election — most likely the outgoing worker's Postgres session still held it — logged `"notifier": false`, and then ran for 17.5 hours as a worker that would never notify anyone. It recovered only incidentally, when the PR #93 deploy restarted it and it happened to win the lock. A lost election at boot should be retried rather than being a permanent, silent death sentence for the process.

admin_emi added 1 commit 2026-07-25 17:47:15 +00:00

alerting: base web/worker liveness on the app heartbeat, not container stdout

secrets-guard / encrypted (pull_request) Successful in 5s

Details

shell-lint / shellcheck (pull_request) Successful in 6s

Details

PR build (required check) / build-backend (pull_request) Has been skipped

Details

PR build (required check) / build-frontend (pull_request) Has been skipped

Details

PR build (required check) / changes (pull_request) Successful in 9s

Details

PR build (required check) / validate-observability (pull_request) Successful in 23s

Details

PR build (required check) / gate (pull_request) Successful in 2s

Details

ba11423fd9

Three of the prod liveness rules were measuring streams that no longer say
anything about the thing they claim to watch.

ProdWorkerContainerSilent was unsatisfiable by construction: prod's alloy
config drops the thermograph_worker container on purpose, so the stream it
queried never reaches Loki and the rule returned zero regardless of worker
health. Firing continuously since 2026-07-24T21:05Z.

ProdWebContainerSilent measured a floor that stopped existing when the app
moved request logging off stdout onto app-json; a web container now emits
~15 uvicorn banner lines for its whole lifetime. It cleared only for the few
minutes after each deploy/autoscale event, producing 20+ false pages in a day.

NotifierHeartbeatMissing{Prod,Beta} matched a bare tag=heartbeat, which was
unambiguous until _start_heartbeat shipped at 2026-07-25T17:24Z and every
uvicorn process began beating under the same tag. The rule that had just
caught a real 17.5h notifier outage would have gone silent on the next one.

Both liveness rules now read the app's own heartbeat filtered by daemon, and
the notifier rules are pinned to daemon=subscription-notifier. db and frontend
keep their container-log rules, which remain valid. Queries verified against
live Loki: web 16, worker 4, notifier 2 per 20m window; beta notifier never
below 1 across 37 consecutive buckets.