From 4e3333ecf53cad3c4f80b3e1bd86613a2fbec459 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Dawid=20Wr=C3=B3blewski?= Date: Sat, 12 Sep 2026 21:48:02 +0200 Subject: [PATCH 1/2] What needs a decision reaches a person by itself (#167) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The R360 collector had been reporting two frame sets nobody's record names for two days, into a container's stdout, and the report reached a person exactly once — because someone went in over SSH to look. The same silence covered the disk, whether the site answers, the nightly copy, server errors and the mail provider. The design kept leaving decisions to a human, and no code path ever carried one to the human. Now, two watchers, because a box cannot report its own death: - deploy/ops-check.sh, hourly on the instance: the disk, the containers, whether the site answers, the age of the nightly copy, preview copies of dev's database that nothing owns, the collector's findings, database deadlines, unhandled errors, and what the mail provider did with ours. It mails OPS_EMAIL when something needs acting on — once, again a day later if it is still true, and once when it stops — and every morning either way, so an empty inbox means "checked" and a missing report is itself the signal. - .github/workflows/watch.yml, every thirty minutes from GitHub: whether the site answers from outside. It opens an `outage` issue and closes it when the site is back, so the label's state is the answer. Three tiers and no more. The reports carry counts and the instance's own figures, never an address, a handle or a line of any log: the mailbox may sit outside the EU. No new provider and no new cost — the mail goes through the transactional provider the application already uses, with the same key. The application's and the proxy's logs move to the host journal, capped at 300 MB. A log inside the container's directory was deleted with the container on every deploy, so the hour before a bad deploy was always gone by the time anyone looked. Preview containers keep a file log, capped. Its first dry run on dev found two real things at once: the disk at 92% (#119) and a copy of dev's database that no preview owned. Co-Authored-By: Claude Opus 5 --- .env.example | 8 + .github/workflows/ci.yml | 17 +- .github/workflows/watch.yml | 95 +++++++++++ SPEC.md | 11 ++ deploy/compose.yaml | 11 ++ deploy/ops-check.sh | 303 ++++++++++++++++++++++++++++++++++++ deploy/preview-up.sh | 1 + deploy/remote-deploy.sh | 80 +++++++++- docs/operations.md | 130 ++++++++++++++++ tasks/plan.md | 11 +- 10 files changed, 660 insertions(+), 7 deletions(-) create mode 100644 .github/workflows/watch.yml create mode 100644 deploy/ops-check.sh create mode 100644 docs/operations.md diff --git a/.env.example b/.env.example index 399b03e..6fb73c5 100644 --- a/.env.example +++ b/.env.example @@ -67,6 +67,14 @@ EMAIL_REGION= # right and fails identically to having no Reply-To at all. EMAIL_REPLY_TO= +# Where the instance's operations report goes (#167, docs/operations.md): an +# ACT NOW message when something needs a decision, and a daily report either +# way. Read on the instance only, by deploy/ops-check.sh — the application +# ignores it. Leave empty and the report reaches the journal and nobody else. +# It carries counts and the instance's own figures, never an address or a line +# of any log, so a mailbox outside the EU is acceptable for it (§7). +OPS_EMAIL= + # Application APP_URL= AUTH_SECRET= diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 2dd7e0e..4c26e57 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -296,6 +296,21 @@ jobs: - name: The nightly copy skips the preview copies run: grep -q "not like 'platform..pr..%'" deploy/backup-db.sh + # #167. The application's log goes to the host journal, because a log + # kept in the container's own directory is deleted with the container — + # which is every deploy. And the hourly check that reads it has to reach + # the instance, or the report that exists to break the silence is itself + # silently missing. + - name: The application logs to the journal + run: | + test "$(grep -c 'driver: journald' deploy/compose.yaml)" -ge 2 + - name: The operations check is shipped and installed + run: | + # Anchored to the scp line's indentation, so this line cannot satisfy itself. + grep -qE '^ +deploy/backup-db.sh deploy/ops-check.sh' .github/workflows/ci.yml + grep -q 'ExecStart=/bin/bash /opt/platform-lite/ops-check.sh' deploy/remote-deploy.sh + bash -n deploy/ops-check.sh + # Smoke on every push and PR (SPEC §6): the database-less project only. No # DATABASE_URL_TEST here on purpose — that is what makes this job prove the # fail-closed behaviour (401s, redirects to /login, 404s) with no database at @@ -491,7 +506,7 @@ jobs: run: | scp -i ~/.ssh/id_deploy \ deploy/compose.yaml deploy/Caddyfile deploy/remote-deploy.sh \ - deploy/backup-db.sh \ + deploy/backup-db.sh deploy/ops-check.sh \ "$HOST:/opt/platform-lite/" - name: Pull the image and restart the container if: steps.wired.outputs.wired == 'true' diff --git a/.github/workflows/watch.yml b/.github/workflows/watch.yml new file mode 100644 index 0000000..a3ce037 --- /dev/null +++ b/.github/workflows/watch.yml @@ -0,0 +1,95 @@ +name: Watch + +# #167: whether the site answers, asked from somewhere that is not the +# instance. The hourly check ON the instance (deploy/ops-check.sh) sees the +# disk, the containers and the nightly copy — and cannot report the one thing +# that silences all of it: the instance itself being gone. A box cannot report +# its own death, so this runs on GitHub's machines. +# +# Where it speaks: a GitHub issue labelled `outage`, opened when the site stops +# answering and closed — with the time it came back — when it answers again. +# That is no new provider and no new cost while the repository is public, it +# reaches the owner's phone through GitHub's own notifications, and its STATE +# is the answer: an open `outage` issue means down, none means up. +# +# Every thirty minutes. GitHub runs scheduled workflows late under load and +# not at all in a repository with no activity for sixty days — both written +# down in docs/operations.md, because a watcher that has quietly stopped looks +# exactly like a site that is fine. If the repository goes private (#163), +# these runs start costing minutes: 48 a day at well under a minute each. + +on: + schedule: + - cron: "7,37 * * * *" + workflow_dispatch: + inputs: + url: + description: "Address to check instead of dev's (to try the alarm without breaking dev)" + required: false + +permissions: + contents: read + issues: write + +# Two runs must not both decide to open the issue. +concurrency: + group: watch + cancel-in-progress: false + +jobs: + answers: + runs-on: ubuntu-latest + timeout-minutes: 5 + env: + URL: ${{ inputs.url || 'https://dev.architektow3d.pl/' }} + GH_TOKEN: ${{ github.token }} + GH_REPO: ${{ github.repository }} + steps: + - name: Does it answer? + id: probe + run: | + # Three tries a minute apart: one slow answer during a deploy is not + # an outage, and an alarm that cries wolf is an alarm nobody reads. + # A 4xx is an answer — the server is up and deciding; only a 5xx, a + # timeout or no connection at all counts as down. + code=000 + for attempt in 1 2 3; do + code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 20 "$URL" || true) + case "$code" in + [1-4][0-9][0-9]) break ;; + esac + [ "$attempt" -eq 3 ] || sleep 30 + done + echo "code=$code" >> "$GITHUB_OUTPUT" + echo "$URL answered ${code} (000 is no answer at all)" + + - name: Open or close the outage issue + env: + CODE: ${{ steps.probe.outputs.code }} + OWNER: ${{ github.repository_owner }} + run: | + open=$(gh issue list --label outage --state open --json number --jq '.[0].number // empty') + now=$(date -u +%Y-%m-%dT%H:%MZ) + case "$CODE" in + [1-4][0-9][0-9]) up=true ;; + *) up=false ;; + esac + + if [ "$up" = false ] && [ -z "$open" ]; then + gh label create outage --color B60205 \ + --description "The site is not answering (opened and closed by .github/workflows/watch.yml)" \ + --force >/dev/null + gh issue create --label outage \ + --title "$URL is not answering" \ + --body "$(printf '%s\n' \ + "Checked from GitHub's machines at $now: three tries a minute apart, last answer \`$CODE\` (\`000\` is no answer at all)." \ + "" \ + "What to do: docs/operations.md, \"The site does not answer\". This issue closes itself when the site answers again." \ + "" \ + "@$OWNER")" + elif [ "$up" = true ] && [ -n "$open" ]; then + gh issue comment "$open" --body "Answering again at $now (\`$CODE\`)." + gh issue close "$open" + else + echo "nothing changed: up=$up, open issue: ${open:-none}" + fi diff --git a/SPEC.md b/SPEC.md index ef89654..1ac865a 100644 --- a/SPEC.md +++ b/SPEC.md @@ -358,6 +358,17 @@ export function ownerKey( **The signing key being shared is the thing production must not inherit** — one `AUTH_SECRET` across environments plus a copy of the rows is how a session from one becomes a session in another; #24 gives production its own. +- **What needs a decision reaches a person by itself** (#167, `docs/operations.md`): every + hour `deploy/ops-check.sh` looks at the instance — disk, containers, whether the site + answers, the nightly copy, preview copies nobody owns, the R360 collector's findings, + database deadlines, server errors, the mail provider's failures and blocks — and mails + `OPS_EMAIL` when something needs acting on, plus a report every morning either way, so an + empty inbox means "checked" and a missing report is itself the signal. Whether the site + answers from outside is `.github/workflows/watch.yml`, which opens and closes an `outage` + issue: a box cannot report its own death. Three tiers and no more. The reports carry counts, + never an address or a log line (§7). Application logs live in the host journal, capped, + because a log inside the container's directory died with every deploy. No new provider and + no new cost: the mail goes through the transactional provider the application already uses. - **Every wait on the database has a deadline, and each environment sets its own** (#172): the pool answers a caller it cannot give a connection to within five seconds instead of queueing them for ever, and the server cuts off a statement that runs past ten seconds or diff --git a/deploy/compose.yaml b/deploy/compose.yaml index 9ae028d..0e1cbf8 100644 --- a/deploy/compose.yaml +++ b/deploy/compose.yaml @@ -18,6 +18,14 @@ services: # guess passwords without limit (the #8 review's trust contract). expose: ["3000"] networks: [platform] + # #167: into the host's journal, not a file in the container's own + # directory. That file is deleted with the container — which is every + # deploy — so the log of the hour before a bad deploy was gone by the time + # anyone looked for it. The journal outlives the container, is capped by + # remote-deploy.sh, and tags every entry with the container's name, which + # compose keeps from one deploy to the next. + logging: + driver: journald caddy: image: caddy:2-alpine @@ -45,6 +53,9 @@ services: S3_UPLOAD_ORIGIN: ${S3_UPLOAD_ORIGIN:?set S3_UPLOAD_ORIGIN to the S3 endpoint origin} depends_on: [app] networks: [platform] + # Same as the app's, for the same reason (#167). + logging: + driver: journald networks: # Created once by the deployment procedure, not by this file, because the diff --git a/deploy/ops-check.sh b/deploy/ops-check.sh new file mode 100644 index 0000000..170a7ed --- /dev/null +++ b/deploy/ops-check.sh @@ -0,0 +1,303 @@ +#!/usr/bin/env bash +# Runs ON the instance, every hour, from platform-ops.timer (#167). Installed +# by remote-deploy.sh; the whole practice around it is docs/operations.md. +# +# What it is for: the design of this system leaves several decisions to a +# person — the collector's unrecorded frame sets (#156), a disk filling up +# (#119), a nightly copy that stopped (#168) — and until now every one of them +# was said into a log nobody reads. This script is the path from the saying to +# the person. It looks, writes what it saw to the journal, and mails when +# something needs a decision; once a day it mails anyway, so that a quiet inbox +# means "checked, nothing to do" rather than "nobody looked". +# +# Three tiers and no more — more than that and the channel dies of noise: +# ACT NOW mailed when it starts, again if it is still true a day later, +# and once more when it stops +# THIS WEEK in the daily report +# RECORD in the daily report, so a number has a history +# +# What it never sends: an address, a handle, a name, or a line of any log. +# The report goes to a mailbox that may well sit outside the EU (§7), so it +# carries counts and the instance's own figures, nothing about anybody. +# +# What it cannot do: report this instance's death. That is +# .github/workflows/watch.yml, from outside. +set -euo pipefail + +ENV_FILE=${ENV_FILE:-/opt/platform-lite/.env} +STATE_DIR=${STATE_DIR:-/var/lib/platform-ops} +BACKUP_RECORD=${BACKUP_RECORD:-/var/lib/platform-backup/last-success} +# 05 UTC is 07:00 in Warsaw in summer and 06:00 in winter: before the day +# starts, and after the nightly copy (03:17) has had its chance. +DIGEST_HOUR_UTC=${DIGEST_HOUR_UTC:-05} + +# Only the variables this script uses. The .env also holds the database +# password, the signing key and the bucket credentials, none of which a +# report has any business carrying into its own environment. +while IFS= read -r line || [ -n "$line" ]; do + case "$line" in + EMAIL_API_KEY=* | EMAIL_PROJECT_ID=* | EMAIL_REGION=* | EMAIL_FROM=* | \ + EMAIL_FROM_NAME=* | OPS_EMAIL=* | SITE_ADDRESS=* | APP_ENV=*) + export "${line%%=*}=${line#*=}" + ;; + esac +done <"$ENV_FILE" + +ENVIRONMENT=${APP_ENV:-unknown} +EMAIL_REGION=${EMAIL_REGION:-fr-par} +mkdir -p "$STATE_DIR" + +act_keys=() +act=() +week=() +record=() +# say . The key names the CONDITION, not the numbers in the +# line: "disk" stays "disk" from 91% to 92%, so a disk that keeps filling is +# one alert, not one an hour. +say() { + local tier=$1 key=$2 + shift 2 + case "$tier" in + act) act_keys+=("$key") && act+=("$*") ;; + week) week+=("$*") ;; + *) record+=("$*") ;; + esac +} + +# --- the disk -------------------------------------------------------------- +# The instance's one disk holds the images, the database, the journal and +# every preview. Full, it stops PostgreSQL writing — dev down, and every +# preview with it. +used=$(df --output=pcent / | tail -1 | tr -dc '0-9') +free=$(df -h --output=avail / | tail -1 | tr -d ' ') +if [ "$used" -ge 90 ]; then + say act disk "disk at ${used}%, ${free} free — when it fills, PostgreSQL stops writing and previews stop starting (#119)" +elif [ "$used" -ge 80 ]; then + say week disk "disk at ${used}%, ${free} free (#119)" +else + say record disk "disk at ${used}%, ${free} free" +fi +images=$(docker images --format '{{.Repository}}' | awk '/platform-lite/ {n++} END {print n+0}') +say record images "$images application images kept on the instance (#119)" + +# --- the containers -------------------------------------------------------- +# `running/starting` is a deploy in progress, not an outage: the check runs on +# the hour and a deploy can land on it. +for name in platform-lite-app-1 platform-lite-caddy-1 postgres; do + state=$(docker inspect --format '{{.State.Status}}{{if .State.Health}}/{{.State.Health.Status}}{{end}}' "$name" 2>/dev/null || echo missing) + case "$state" in + running | running/healthy | running/starting) say record "container-$name" "$name: $state" ;; + *) say act "container-$name" "$name is $state" ;; + esac +done + +# --- the site, from here --------------------------------------------------- +# Through the proxy, as a visitor reaches it — but resolved to this machine, +# so the answer does not depend on the network hairpinning back in. Whether +# the site answers from OUTSIDE is watch.yml's question. +if [ -n "${SITE_ADDRESS:-}" ]; then + code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 20 \ + --resolve "$SITE_ADDRESS:443:127.0.0.1" "https://$SITE_ADDRESS/" || true) + case "$code" in + [1-4][0-9][0-9]) say record site "https://$SITE_ADDRESS/ answers $code" ;; + *) say act site "https://$SITE_ADDRESS/ answers ${code:-nothing} from the instance itself" ;; + esac +fi + +# --- the nightly copy of the databases (#168) ------------------------------ +if [ ! -f "$BACKUP_RECORD" ]; then + say act backup "no copy of the databases has ever succeeded on this instance (#168)" +else + age_h=$((($(date +%s) - $(stat -c %Y "$BACKUP_RECORD")) / 3600)) + # 36 hours: a night can be late (the timer has five minutes of jitter and + # catches up after a reboot), but two nights missed is a copy that stopped. + if [ "$age_h" -gt 36 ]; then + say act backup "the newest copy of the databases is ${age_h} h old — the nightly copy has stopped (#168): $(cat "$BACKUP_RECORD")" + else + say record backup "databases copied ${age_h} h ago: $(cat "$BACKUP_RECORD")" + fi +fi + +# --- preview copies nobody owns (#113) ------------------------------------- +orphans=0 +copies=0 +for db in $(docker exec postgres psql -U postgres -At -d postgres \ + -c "select datname from pg_database where datname like 'platform\_pr\_%'" 2>/dev/null || true); do + copies=$((copies + 1)) + [ -n "$(docker ps -a --filter "name=^pr-${db#platform_pr_}$" --format '{{.Names}}')" ] || + orphans=$((orphans + 1)) +done +if [ "$orphans" -gt 0 ]; then + say week previews "$orphans preview database(s) with no container — copies of dev's accounts; the next preview sweeps them, or docs/dev-environment.md" +else + say record previews "$copies preview database(s), each with its container" +fi + +# --- what the application said in the last day ------------------------------ +# Read from the journal by container NAME, which compose keeps across a +# deploy — `docker logs` would only see the container started by the last one. +app_log() { + journalctl --quiet --no-pager --output=cat \ + CONTAINER_NAME=platform-lite-app-1 --since "24 hours ago" 2>/dev/null || true +} +log=$(app_log) +unrecorded=$(printf '%s\n' "$log" | + sed -n 's/^\[r360\] collector: \([0-9][0-9]*\) frame set(s) no record names.*/\1/p' | tail -1) +if [ -n "$unrecorded" ] && [ "$unrecorded" -gt 0 ]; then + say week collector "the R360 collector found $unrecorded frame set(s) that no record names and left them alone — a person decides (#156); the list: journalctl CONTAINER_NAME=platform-lite-app-1 | grep collector" +fi +collector_failed=$(printf '%s\n' "$log" | awk '/^\[r360\] collector: the (run|report) failed/ {n++} END {print n+0}') +[ "$collector_failed" -eq 0 ] || say week collector-failed "the R360 collector failed $collector_failed time(s)" +# Counts by kind, never the lines: a log line can carry an address or a path +# with a handle in it, and this report leaves the instance. +stalls=$(printf '%s\n' "$log" | awk '/^\[db\]/ {n++} END {print n+0}') +[ "$stalls" -eq 0 ] || say week db "$stalls database deadline(s) hit (#172) — which ones: journalctl CONTAINER_NAME=platform-lite-app-1 | grep '\[db\]'" +errors=$(printf '%s\n' "$log" | LC_ALL=C.UTF-8 awk '/⨯|Uncaught|Unhandled/ {n++} END {print n+0}') +if [ "$errors" -gt 0 ]; then + say week errors "$errors unhandled server error(s) — journalctl CONTAINER_NAME=platform-lite-app-1 --since '24 hours ago'" +else + say record errors "no unhandled server errors" +fi + +# --- mail: what the provider did with ours (#22, #23) ----------------------- +headers=$(mktemp) +trap 'rm -f "$headers"' EXIT +chmod 600 "$headers" +tem() { + curl -sS --fail-with-body --max-time 30 -H @"$headers" "$@" +} +tem_base="https://api.scaleway.com/transactional-email/v1alpha1/regions/$EMAIL_REGION" +if [ -n "${EMAIL_API_KEY:-}" ] && [ -n "${EMAIL_PROJECT_ID:-}" ]; then + # Through a file, not argv: /proc//cmdline is world-readable here. + printf 'X-Auth-Token: %s\n' "$EMAIL_API_KEY" >"$headers" + since=$(date -u -d '24 hours ago' +%Y-%m-%dT%H:%M:%SZ) + if stats=$(tem "$tem_base/statistics?project_id=$EMAIL_PROJECT_ID&since=$since"); then + read -r sent failed <<<"$(printf '%s' "$stats" | python3 -c 'import json,sys; d=json.load(sys.stdin); print(d.get("total_count",0), d.get("failed_count",0))' || true)" + sent=${sent:-0} + failed=${failed:-0} + # A handful of failures in a small volume is a bad address; a quarter of + # everything failing is the domain's reputation going, and the first sign + # anyone else would notice is "I never got the e-mail". + if [ "$sent" -ge 4 ] && [ $((failed * 4)) -ge "$sent" ]; then + say act mail "$failed of $sent messages failed in 24 h — the sending domain's reputation, or the provider" + elif [ "$failed" -gt 0 ]; then + say week mail "$failed of $sent messages failed in 24 h (a bounce or a rejection)" + else + say record mail "$sent messages in 24 h, none failed" + fi + else + say week mail "the mail provider's statistics could not be read" + fi + # The provider blocks an address after a hard bounce or a complaint. Only the + # count is read, and only a rise is news. + domain=$(tem "$tem_base/domains?project_id=$EMAIL_PROJECT_ID" 2>/dev/null | + python3 -c 'import json,sys; ds=json.load(sys.stdin).get("domains",[]); print(ds[0]["id"] if ds else "")' 2>/dev/null || true) + if [ -n "$domain" ]; then + blocked=$(tem "$tem_base/blocklists?domain_id=$domain&page_size=1" 2>/dev/null | + python3 -c 'import json,sys; print(json.load(sys.stdin).get("total_count",0))' 2>/dev/null || echo "") + before=$(cat "$STATE_DIR/blocked" 2>/dev/null || echo "") + if [ -n "$blocked" ]; then + if [ -n "$before" ] && [ "$blocked" -gt "$before" ]; then + say week blocked "the provider now blocks $blocked address(es), up from $before — a hard bounce or a complaint" + else + say record blocked "the provider blocks $blocked address(es)" + fi + printf '%s\n' "$blocked" >"$STATE_DIR/blocked" + fi + fi +fi + +# --- the report -------------------------------------------------------------- +report() { + local line + if [ ${#act[@]} -gt 0 ]; then + echo "ACT NOW" + for line in "${act[@]}"; do echo " - $line"; done + echo + fi + if [ ${#week[@]} -gt 0 ]; then + echo "THIS WEEK" + for line in "${week[@]}"; do echo " - $line"; done + echo + fi + echo "RECORD" + for line in "${record[@]}"; do echo " - $line"; done + echo + echo "Checked $(date -u +%Y-%m-%dT%H:%M:%SZ) on $(hostname). What each line means and what to do: docs/operations.md" +} +body=$(report) +# The journal always gets the whole report, mailed or not. +printf '%s\n' "$body" + +send() { + local subject=$1 + if [ -z "${OPS_EMAIL:-}" ]; then + echo "OPS_EMAIL is not set: \"$subject\" reached this journal and nobody else" + return 0 + fi + if [ -z "${EMAIL_API_KEY:-}" ] || [ -z "${EMAIL_PROJECT_ID:-}" ] || [ -z "${EMAIL_FROM:-}" ]; then + echo "the mail provider is not configured in $ENV_FILE: \"$subject\" was not sent" >&2 + return 1 + fi + local payload + payload=$(SUBJECT="$subject" BODY="$body" python3 -c ' +import json, os +sender = {"email": os.environ["EMAIL_FROM"]} +if os.environ.get("EMAIL_FROM_NAME"): + sender["name"] = os.environ["EMAIL_FROM_NAME"] +print(json.dumps({ + "project_id": os.environ["EMAIL_PROJECT_ID"], + "from": sender, + "to": [{"email": os.environ["OPS_EMAIL"]}], + "subject": os.environ["SUBJECT"], + "text": os.environ["BODY"], +}))') + tem -H 'Content-Type: application/json' --data-binary "$payload" "$tem_base/emails" >/dev/null + echo "mailed: $subject" +} + +# What was last mailed as ACT NOW, as condition keys — so an alert goes out +# when the SET of problems changes, not when a number inside one does. +now_keys=$(printf '%s\n' "${act_keys[@]}" | sort -u | tr '\n' ' ') +now_keys=${now_keys% } +last_keys=$(sed -n 1p "$STATE_DIR/act" 2>/dev/null || true) +last_sent=$(sed -n 2p "$STATE_DIR/act" 2>/dev/null || echo 0) +now=$(date +%s) +status=0 + +if [ -n "$now_keys" ]; then + if [ "$now_keys" != "$last_keys" ] || [ $((now - last_sent)) -ge 86400 ]; then + if send "[$ENVIRONMENT] ACT NOW: ${act[0]}"; then + printf '%s\n%s\n' "$now_keys" "$now" >"$STATE_DIR/act" + else + status=1 + fi + fi +elif [ -n "$last_keys" ]; then + if send "[$ENVIRONMENT] resolved: $last_keys"; then + rm -f "$STATE_DIR/act" + else + status=1 + fi +fi + +# Once a day whatever the state: the report that says "nothing to do" is what +# makes an empty inbox mean something. Its absence by breakfast is itself the +# signal — the instance, the timer or the mail path is broken. +today=$(date -u +%F) +if [ "$(date -u +%H)" = "$DIGEST_HOUR_UTC" ] && [ "$(cat "$STATE_DIR/digest-day" 2>/dev/null || true)" != "$today" ]; then + if [ ${#act[@]} -gt 0 ]; then + summary="${#act[@]} to act on" + elif [ ${#week[@]} -gt 0 ]; then + summary="${#week[@]} to look at this week" + else + summary="nothing to do" + fi + if send "[$ENVIRONMENT] daily: $summary"; then + printf '%s\n' "$today" >"$STATE_DIR/digest-day" + else + status=1 + fi +fi + +exit "$status" diff --git a/deploy/preview-up.sh b/deploy/preview-up.sh index 3f10a04..6b20f38 100644 --- a/deploy/preview-up.sh +++ b/deploy/preview-up.sh @@ -189,6 +189,7 @@ docker run --detach --name "$NAME" \ --restart unless-stopped \ --network platform \ --memory 512m \ + --log-opt max-size=10m --log-opt max-file=3 \ --env-file /opt/platform-lite/.env \ --env DATABASE_URL \ --env "APP_URL=https://$HOSTNAME_" \ diff --git a/deploy/remote-deploy.sh b/deploy/remote-deploy.sh index 1151c92..1644019 100644 --- a/deploy/remote-deploy.sh +++ b/deploy/remote-deploy.sh @@ -134,9 +134,10 @@ if [ "$timer_status" -ne 0 ]; then echo " the deployment continues — see docs/backup-and-restore.md" fi -# Until #167 gives reports a way to reach a person, the deployment is the one -# routine that a human already watches. It only warns: a stale copy is not a -# reason to refuse to deploy, it is a reason to know. +# The hourly check (#167) mails this when it is true; the deployment says it too, +# because a deploy log is read at the moment someone is already paying +# attention. It only warns: a stale copy is not a reason to refuse to deploy, +# it is a reason to know. last_copy=/var/lib/platform-backup/last-success if [ ! -f "$last_copy" ]; then echo "WARNING: no database copy has ever succeeded on this instance (#168)" @@ -146,6 +147,79 @@ elif [ $(($(date +%s) - $(stat -c %Y "$last_copy"))) -gt 172800 ]; then echo " check: systemctl status platform-backup.timer" fi +# #167: the hourly look at this instance, and the one place its findings are +# turned into a message to a person — deploy/ops-check.sh, docs/operations.md. +# Installed the same way as the copy above and for the same reasons, including +# the subshell and the captured status; it must never stop a deployment. +install_ops_timer() ( + set -e + units=$(mktemp -d) + trap 'rm -rf "$units"' EXIT +cat >"$units/platform-ops.service" <<'UNIT' +[Unit] +Description=Look at this instance and tell a person what needs a decision (#167) +Requires=docker.service +After=docker.service + +[Service] +Type=oneshot +User=ubuntu +# The application's log is in the journal (compose.yaml), and reading another +# unit's entries takes this group. Granted to the service, not to the account. +SupplementaryGroups=systemd-journal +StateDirectory=platform-ops +PrivateTmp=true +TimeoutStartSec=300 +ExecStart=/bin/bash /opt/platform-lite/ops-check.sh +UNIT +cat >"$units/platform-ops.timer" <<'UNIT' +[Unit] +Description=Hourly look at this instance (#167) + +[Timer] +OnCalendar=hourly +Persistent=true +RandomizedDelaySec=120 + +[Install] +WantedBy=timers.target +UNIT +# The journal is where the application's log now lives, so it is also what +# could fill the disk being watched. Capped here rather than left to journald's +# default, which is a tenth of the filesystem. +cat >"$units/platform-lite.conf" <<'UNIT' +[Journal] +SystemMaxUse=300M +MaxRetentionSec=30day +UNIT + units_changed=false + for unit in platform-ops.service platform-ops.timer; do + if ! cmp -s "$units/$unit" "/etc/systemd/system/$unit"; then + sudo install -m 644 "$units/$unit" "/etc/systemd/system/$unit" + units_changed=true + fi + done + if [ "$units_changed" = true ]; then + echo "ops timer: units installed" + sudo systemctl daemon-reload + fi + sudo systemctl enable --now platform-ops.timer >/dev/null + if ! cmp -s "$units/platform-lite.conf" /etc/systemd/journald.conf.d/platform-lite.conf; then + sudo install -d -m 755 /etc/systemd/journald.conf.d + sudo install -m 644 "$units/platform-lite.conf" /etc/systemd/journald.conf.d/platform-lite.conf + sudo systemctl restart systemd-journald + echo "journal: capped at 300M" + fi +) +set +e +install_ops_timer +ops_status=$? +set -e +if [ "$ops_status" -ne 0 ]; then + echo "WARNING: the hourly operations check could not be installed (#167);" + echo " the deployment continues — see docs/operations.md" +fi + container=$(docker compose ps --quiet app) for attempt in $(seq 1 60); do status=$(docker inspect --format '{{.State.Health.Status}}' "$container" 2>/dev/null || echo starting) diff --git a/docs/operations.md b/docs/operations.md new file mode 100644 index 0000000..dd21437 --- /dev/null +++ b/docs/operations.md @@ -0,0 +1,130 @@ +# Operations — knowing what an environment is doing + +What this system watches, how often, where each finding appears, who it +reaches, and what it means someone should do. Written for #167, on 12.09.2026, +after a report that had been warning into a container's log for two days +reached a person exactly once — because someone went looking. + +## Is everything fine right now? + +Two places, and nothing else to open: + +1. **The last daily report in the inbox named by `OPS_EMAIL`.** One arrives + every morning (05:00 UTC) whether or not anything is wrong. Its subject + says which: `[dev] daily: nothing to do`, `… 2 to look at this week`, or + `… 1 to act on`. +2. **Issues labelled [`outage`](https://github.com/Devski/platform-lite/issues?q=label%3Aoutage) + on GitHub.** An open one means the site is not answering from outside; + none means it is. + +**No daily report by 08:00 Warsaw time is itself the signal**: the instance, +its timer or the mail path is broken. Look at the `outage` label first — if the +site answers from outside, the instance is up and the report is what failed +(`systemctl status platform-ops.service` over SSH). + +## The two watchers + +| | Where it runs | How often | What it can see | What it cannot | +| ----------------------------- | ------------------------------------- | ---------------- | ------------------------------------------------------------------------------------ | --------------------------- | +| `deploy/ops-check.sh` | on the instance, `platform-ops.timer` | every hour | the disk, the containers, the nightly copy, the application's log, the mail provider | its own instance being down | +| `.github/workflows/watch.yml` | on GitHub's machines | every 30 minutes | whether the site answers from the internet | anything inside | + +They are deliberately two. A box cannot report its own death, and the thing +outside cannot see the disk. + +## The three tiers + +At most three, because a channel that says everything is a channel nobody +reads — which is the failure this document exists to prevent, one level up. + +- **ACT NOW** — mailed within the hour it starts, again if still true a day + later, and once more when it stops (`[dev] resolved: …`). A number changing + inside the same problem (disk 91% → 92%) does not send another. +- **THIS WEEK** — in the daily report. +- **RECORD** — in the daily report, so a figure has a history to compare with. + +## What each signal means, and what to do + +| Signal | Tier | What to do | +| ------------------------------------------------------ | --------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| Disk at 90% or more | ACT NOW | Full, PostgreSQL stops writing — dev and every preview go down together. The usual cause is application images: one per commit, nothing prunes (#119). `docker image ls ghcr.io/devski/platform-lite` and remove the oldest ones no container uses; keep the last few for rollback. | +| Disk at 80–89% | this week | The same, with time to plan it. | +| A container is missing, stopped or unhealthy | ACT NOW | `docker ps -a`; for the app, `journalctl CONTAINER_NAME=platform-lite-app-1 -n 100`. Rolling back is redeploying an older tag (SPEC §8). | +| The site does not answer from the instance itself | ACT NOW | The proxy or the app — the container lines in the same report say which. | +| The site does not answer from outside (`outage` issue) | ACT NOW | If the report from the instance still arrives, it is the network, DNS or the certificate; if it has also stopped, the instance is down — the OVH console. | +| The newest copy of the databases is over 36 h old | ACT NOW | The nightly copy has stopped (#168). `systemctl status platform-backup.service`, `journalctl -u platform-backup.service -n 50`. A refusal to shrink is explained in `deploy/backup-db.sh`. | +| No copy has ever succeeded | ACT NOW | A new instance where the timer was never installed, or it never once worked: `docs/backup-and-restore.md`. | +| Preview databases with no container | this week | Copies of dev's accounts, left by a preview removed some other way than closing its pull request. The next preview sweeps them; by hand: `docs/dev-environment.md`. | +| The R360 collector found frame sets no record names | this week | By design it deletes nothing it cannot account for, and waits for a person (#156). The list is in the log: `journalctl CONTAINER_NAME=platform-lite-app-1 \| grep collector`. Decide per set; nothing is lost by waiting a week. | +| The R360 collector failed | this week | The same log. A sweep that stops reporting is worse than one that fails loudly — this is the loud version. | +| Database deadlines hit | this week | #172. Which bound and which path are in the log (`grep '\[db\]'`); one a day is noise, a pattern is a query or a lock to look at. | +| Unhandled server errors | this week | The log for the last day. | +| A quarter or more of mail failed (4+ sent) | ACT NOW | The sending domain's reputation or the provider — people are not receiving verification messages. Scaleway console → Transactional Email; SPF/DKIM/DMARC per G8. | +| Some mail failed | this week | A bounce or a rejection — usually one bad address. | +| The provider blocks more addresses than yesterday | this week | A hard bounce or a complaint. The addresses are in the Scaleway console, deliberately not in the report. | + +## What the report never carries + +No e-mail address, handle, name, or line of any log — only counts and the +instance's own figures. The mailbox it goes to may sit outside the EU, and +§7 keeps personal data out of that path. Everything a count points at is one +command away on the instance, where it already is. + +## Setting it up + +On the instance, in `/opt/platform-lite/.env`: + +``` +OPS_EMAIL= +``` + +Nothing else: it sends through the transactional mail provider the application +already uses (#22), with the same key. Until `OPS_EMAIL` is set, every report +reaches the journal and nobody else — and says so in its last line. + +The timer, the journal's cap and the unit files are installed by every +deployment (`deploy/remote-deploy.sh`). To run a check now: + +``` +sudo systemctl start platform-ops.service +journalctl -u platform-ops.service -n 40 --no-pager +``` + +To try the outside alarm without breaking dev, run the `Watch` workflow by +hand with an address that cannot answer (`https://down.invalid/`): it opens an +`outage` issue. The next scheduled run against dev closes it again. + +## Logs + +The application's and the proxy's logs go to the host's journal +(`deploy/compose.yaml`), not to a file inside the container's directory. +That file is deleted with the container, which is every deploy — so until +#167 the log of the hour before a bad deploy was gone by the time anyone +looked for it. The journal is capped at 300 MB and thirty days +(`/etc/systemd/journald.conf.d/platform-lite.conf`), and every entry carries +the container's name, which compose keeps across deploys: + +``` +journalctl CONTAINER_NAME=platform-lite-app-1 --since "2 hours ago" +``` + +Preview containers keep Docker's file log, capped at three 10 MB files: they +are throwaway, and their log goes with them on purpose. + +## What is not covered yet + +Said here so that silence about them is not read as "checked": + +- **PostgreSQL's own log** stays in Docker's file log. The container was + started by cloud-init with `docker run` (#2), and moving it means recreating + the database container — not a change to make in passing. +- **Production** does not exist yet (#24). Both watchers take it by adding an + address and an `OPS_EMAIL` on its instance; its managed database's own + alerts are OVH's and belong in #24. +- **The watcher watching itself.** GitHub delays scheduled runs under load and + disables them in a repository with no activity for sixty days. The daily + report cannot see whether `watch.yml` ran. If the repository goes quiet for + two months, re-enable the workflow in the Actions tab. +- **Shipping logs somewhere else** was considered and not done: it means a new + provider, a recurring cost, and log lines that can carry personal data + leaving the EU (§7). The instance speaking for itself covers the need today. diff --git a/tasks/plan.md b/tasks/plan.md index 4739387..046f547 100644 --- a/tasks/plan.md +++ b/tasks/plan.md @@ -128,9 +128,14 @@ in under 5 minutes (manual walkthrough); e2e green. copy, and the staleness warning still depends on someone reading a deploy log (#167). - [#167](https://github.com/Devski/platform-lite/issues/167) The state of an environment, and the reports that reach nobody (`deployment`, `enhancement`). Found 12.09.2026 while reading the - R360 collector's report over SSH: it warns into a container's stdout, and that is the whole of - the path from "a human decides" (#156) to the human. The same silence covers the disk (#119), - whether the site answers at all, unhandled errors, and mail bounces. #168 was split out of it. + R360 collector's report over SSH: it warned into a container's stdout, and that was the whole + of the path from "a human decides" (#156) to the human. **Built 12.09.2026** + (`docs/operations.md`): an hourly check on the instance that mails what needs a decision and + a report every morning either way, an outside check on GitHub that opens and closes an + `outage` issue, and application logs moved to the host journal so a deploy no longer deletes + them. Its first dry run on dev found two real things at once: the disk at 92% (#119) and a + preview copy of dev's database nobody owned. **Open until `OPS_EMAIL` is set on the instance + and the first daily report has arrived** — the recipient is Dawid's to choose. - [#163](https://github.com/Devski/platform-lite/issues/163) Take the repository private again (`decision`, `infra`). Measured 12.09.2026: ~30 CI runs a day at ~11.9 billable minutes each, ~11,000 a month. Free would leave `main` unguarded again, so it means Pro — about $52 a month From 7f1e7387f6b6f6c3b02c0ccda7c86a7de44c4cfc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Dawid=20Wr=C3=B3blewski?= Date: Sat, 12 Sep 2026 22:09:04 +0200 Subject: [PATCH 2/2] What the reviews found in the operations check (#167) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The worst of it was the failure path the check exists for. `send` was only ever called as an `if` condition, and bash switches `set -e` off inside a function called that way — so a mail the provider refused ran on to "mailed", returned success, and was recorded as sent: the next attempt a day later, the daily report marked done. The same session caught this trap in remote-deploy.sh, and it was written again here. Every step in send now says itself what happens when it fails, and a missing OPS_EMAIL no longer counts as delivered, so the first real recipient still gets the standing alert. The rest was about ending in silence exactly when it mattered: - Docker unreachable made the first pipeline fail and the script stop before writing a report, and `Requires=docker.service` would have kept the check from starting at all. Now Docker not answering is itself an ACT NOW line, every call that can hang has a time limit, and the unit only Wants Docker. - A full disk would have stopped the mail at the header file. The key now reaches curl through a file descriptor — no disk, no argv, and exported to nothing else the script runs. - An unreadable journal read as "no unhandled server errors". A read that fails says so; zero lines from a container up longer than the collector's interval says the log is not being read. - A mail provider error reset the blocklist baseline to 0, and the next good read reported a rise that never happened. Only a count actually read becomes the baseline, matched to the sending domain by name. - The subject was always the first check's line, so a backup stopping while the disk alert stood would have arrived looking like the disk alert again. It is named after what is new, and each condition resolves on its own. - One slow answer on one core would have mailed ACT NOW and "resolved" an hour apart. The site, the containers and Docker need two looks in a row. - The daily report retries the next hour if its hour's run failed or was late. - The body is one function, so a deploy rewriting the file mid-run cannot make bash run half of each version. And from the security lane: the journal is kept two weeks with a file a day, so the retention is real rather than "a month, give or take"; the application's lines are kept out of /var/log/syslog, where Ubuntu would have made a second, uncapped copy; the unit runs with NoNewPrivileges and a read-only system; the watcher checks https addresses only, holds its token in the one step that needs it, locks the issue it opens, and a hand-run drill has its own label so it can never open or close dev's real alarm. Failed queries being logged with their parameters — session tokens among them — is filed as #186. Verified on the instance under the unit's exact sandbox (systemd-run with the same properties): Docker answers, the journal is readable through the supplementary group, the mail domain is found by name, and no alert state is recorded while there is no recipient. Co-Authored-By: Claude Opus 5 --- .github/workflows/ci.yml | 14 +- .github/workflows/watch.yml | 51 ++-- deploy/compose.yaml | 7 + deploy/ops-check.sh | 531 +++++++++++++++++++++++------------- deploy/remote-deploy.sh | 47 +++- docs/operations.md | 32 ++- 6 files changed, 468 insertions(+), 214 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 4c26e57..e336b3c 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -302,13 +302,25 @@ jobs: # the instance, or the report that exists to break the silence is itself # silently missing. - name: The application logs to the journal + env: + APP_IMAGE: ghcr.io/example/app:validate + SITE_ADDRESS: dev.example.invalid + S3_ORIGIN: https://bucket.example.invalid + S3_UPLOAD_ORIGIN: https://endpoint.example.invalid run: | - test "$(grep -c 'driver: journald' deploy/compose.yaml)" -ge 2 + # Read from the resolved configuration, not grepped: a commented-out + # line or one under the wrong service must not pass. + : > deploy/.env + docker compose --file deploy/compose.yaml config --format json | + jq -e '.services.app.logging.driver == "journald" and .services.caddy.logging.driver == "journald"' + rm deploy/.env - name: The operations check is shipped and installed run: | # Anchored to the scp line's indentation, so this line cannot satisfy itself. grep -qE '^ +deploy/backup-db.sh deploy/ops-check.sh' .github/workflows/ci.yml grep -q 'ExecStart=/bin/bash /opt/platform-lite/ops-check.sh' deploy/remote-deploy.sh + # Defined is not called: the installer has to be invoked on a line of its own. + grep -qxE 'install_ops_timer' deploy/remote-deploy.sh bash -n deploy/ops-check.sh # Smoke on every push and PR (SPEC §6): the database-less project only. No diff --git a/.github/workflows/watch.yml b/.github/workflows/watch.yml index a3ce037..6b3715d 100644 --- a/.github/workflows/watch.yml +++ b/.github/workflows/watch.yml @@ -24,11 +24,12 @@ on: workflow_dispatch: inputs: url: - description: "Address to check instead of dev's (to try the alarm without breaking dev)" + description: "An https address to check instead of dev's — a drill, kept apart from the real alarm under the outage-drill label" required: false +# Nothing is checked out and nothing is read from the repository: the one thing +# this needs is to open and close an issue. permissions: - contents: read issues: write # Two runs must not both decide to open the issue. @@ -42,19 +43,27 @@ jobs: timeout-minutes: 5 env: URL: ${{ inputs.url || 'https://dev.architektow3d.pl/' }} - GH_TOKEN: ${{ github.token }} - GH_REPO: ${{ github.repository }} + # A drill has its own label, so trying the alarm against an address that + # cannot answer never opens — or closes — dev's real outage issue. + LABEL: ${{ inputs.url && 'outage-drill' || 'outage' }} steps: - name: Does it answer? id: probe run: | - # Three tries a minute apart: one slow answer during a deploy is not - # an outage, and an alarm that cries wolf is an alarm nobody reads. - # A 4xx is an answer — the server is up and deciding; only a 5xx, a - # timeout or no connection at all counts as down. + # https only, and passed to curl as a URL rather than as an argument: + # the address can come from a person running this by hand, and a + # value starting with a dash, or a file:// one, is not an address. + case "$URL" in + https://*) ;; + *) echo "::error::only https addresses are checked, not: $URL"; exit 1 ;; + esac + # Three tries thirty seconds apart: one slow answer during a deploy is + # not an outage, and an alarm that cries wolf is an alarm nobody + # reads. A 4xx is an answer — the server is up and deciding; only a + # 5xx, a timeout or no connection at all counts as down. code=000 for attempt in 1 2 3; do - code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 20 "$URL" || true) + code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 20 --proto '=https' --url "$URL" || true) case "$code" in [1-4][0-9][0-9]) break ;; esac @@ -67,8 +76,12 @@ jobs: env: CODE: ${{ steps.probe.outputs.code }} OWNER: ${{ github.repository_owner }} + # Here and only here: the step above runs curl against an address a + # person may have typed, and has no use for a token. + GH_TOKEN: ${{ github.token }} + GH_REPO: ${{ github.repository }} run: | - open=$(gh issue list --label outage --state open --json number --jq '.[0].number // empty') + open=$(gh issue list --label "$LABEL" --state open --json number --jq '.[0].number // empty') now=$(date -u +%Y-%m-%dT%H:%MZ) case "$CODE" in [1-4][0-9][0-9]) up=true ;; @@ -76,20 +89,24 @@ jobs: esac if [ "$up" = false ] && [ -z "$open" ]; then - gh label create outage --color B60205 \ + gh label create "$LABEL" --color B60205 \ --description "The site is not answering (opened and closed by .github/workflows/watch.yml)" \ --force >/dev/null - gh issue create --label outage \ + issue=$(gh issue create --label "$LABEL" \ --title "$URL is not answering" \ --body "$(printf '%s\n' \ - "Checked from GitHub's machines at $now: three tries a minute apart, last answer \`$CODE\` (\`000\` is no answer at all)." \ + "Checked from GitHub's machines at $now: three tries thirty seconds apart, last answer \`$CODE\` (\`000\` is no answer at all)." \ "" \ - "What to do: docs/operations.md, \"The site does not answer\". This issue closes itself when the site answers again." \ + "What to do: docs/operations.md, \"What each signal means\". This issue closes itself when the site answers again." \ "" \ - "@$OWNER")" + "@$OWNER")") + # Locked: the thread notifies the owner, so it is not a place for + # anyone passing by to post "run this to fix it". Collaborators — + # and this workflow — can still write in it. + gh issue lock "$issue" || true elif [ "$up" = true ] && [ -n "$open" ]; then - gh issue comment "$open" --body "Answering again at $now (\`$CODE\`)." + gh issue comment "$open" --body "Answering again at $now (\`$CODE\`)." || true gh issue close "$open" else - echo "nothing changed: up=$up, open issue: ${open:-none}" + echo "nothing changed: up=$up, open $LABEL issue: ${open:-none}" fi diff --git a/deploy/compose.yaml b/deploy/compose.yaml index 0e1cbf8..80a953e 100644 --- a/deploy/compose.yaml +++ b/deploy/compose.yaml @@ -26,6 +26,11 @@ services: # compose keeps from one deploy to the next. logging: driver: journald + # The tag is what rsyslog is told to leave alone (remote-deploy.sh), so + # the lines are kept once, in the capped journal, and not again in + # /var/log/syslog. + options: + tag: platform-lite-app caddy: image: caddy:2-alpine @@ -56,6 +61,8 @@ services: # Same as the app's, for the same reason (#167). logging: driver: journald + options: + tag: platform-lite-caddy networks: # Created once by the deployment procedure, not by this file, because the diff --git a/deploy/ops-check.sh b/deploy/ops-check.sh index 170a7ed..afeb731 100644 --- a/deploy/ops-check.sh +++ b/deploy/ops-check.sh @@ -12,7 +12,7 @@ # # Three tiers and no more — more than that and the channel dies of noise: # ACT NOW mailed when it starts, again if it is still true a day later, -# and once more when it stops +# and once more, per condition, when it stops # THIS WEEK in the daily report # RECORD in the daily report, so a number has a history # @@ -22,159 +22,248 @@ # # What it cannot do: report this instance's death. That is # .github/workflows/watch.yml, from outside. +# +# Written for the moments it exists for. Docker hung, the disk full, the +# journal unreadable, the mail provider down: each has to end in a line that +# says so, never in a script that stopped before writing anything. So every +# call that can hang has a time limit, nothing is written to disk on the way +# to a mail, and the body is one function — a deploy that rewrites this file +# mid-run cannot make bash execute half of each version. set -euo pipefail ENV_FILE=${ENV_FILE:-/opt/platform-lite/.env} STATE_DIR=${STATE_DIR:-/var/lib/platform-ops} BACKUP_RECORD=${BACKUP_RECORD:-/var/lib/platform-backup/last-success} # 05 UTC is 07:00 in Warsaw in summer and 06:00 in winter: before the day -# starts, and after the nightly copy (03:17) has had its chance. +# starts, and after the nightly copy (03:17) has had its chance. The daily +# report goes at the first run AT OR AFTER this hour, so a late or failed run +# is retried the next hour rather than skipped until tomorrow. DIGEST_HOUR_UTC=${DIGEST_HOUR_UTC:-05} - -# Only the variables this script uses. The .env also holds the database -# password, the signing key and the bucket credentials, none of which a -# report has any business carrying into its own environment. -while IFS= read -r line || [ -n "$line" ]; do - case "$line" in - EMAIL_API_KEY=* | EMAIL_PROJECT_ID=* | EMAIL_REGION=* | EMAIL_FROM=* | \ - EMAIL_FROM_NAME=* | OPS_EMAIL=* | SITE_ADDRESS=* | APP_ENV=*) - export "${line%%=*}=${line#*=}" - ;; - esac -done <"$ENV_FILE" - -ENVIRONMENT=${APP_ENV:-unknown} -EMAIL_REGION=${EMAIL_REGION:-fr-par} -mkdir -p "$STATE_DIR" +# Conditions one bad look can produce on one core: a slow answer during an +# image pull, a container being recreated by a deploy, the first run after a +# boot. They are ACT NOW only when the previous hour saw them too. +FLAKY=" docker site container-platform-lite-app-1 container-platform-lite-caddy-1 container-postgres " act_keys=() act=() week=() record=() +now_seen=() +declare -A act_line=() +declare -A was_seen=() + # say . The key names the CONDITION, not the numbers in the -# line: "disk" stays "disk" from 91% to 92%, so a disk that keeps filling is -# one alert, not one an hour. +# line: "disk" stays "disk" from 91% to 92%, so a disk that keeps filling is one +# alert, not one an hour. say() { local tier=$1 key=$2 shift 2 case "$tier" in - act) act_keys+=("$key") && act+=("$*") ;; + act) + now_seen+=("$key") + if [[ $FLAKY == *" $key "* ]] && [ -z "${was_seen[$key]:-}" ]; then + week+=("$* — seen once; ACT NOW if it is still true next hour") + return 0 + fi + act_keys+=("$key") + act+=("$*") + act_line[$key]="$*" + ;; week) week+=("$*") ;; *) record+=("$*") ;; esac } -# --- the disk -------------------------------------------------------------- -# The instance's one disk holds the images, the database, the journal and -# every preview. Full, it stops PostgreSQL writing — dev down, and every -# preview with it. -used=$(df --output=pcent / | tail -1 | tr -dc '0-9') -free=$(df -h --output=avail / | tail -1 | tr -d ' ') -if [ "$used" -ge 90 ]; then - say act disk "disk at ${used}%, ${free} free — when it fills, PostgreSQL stops writing and previews stop starting (#119)" -elif [ "$used" -ge 80 ]; then - say week disk "disk at ${used}%, ${free} free (#119)" -else - say record disk "disk at ${used}%, ${free} free" -fi -images=$(docker images --format '{{.Repository}}' | awk '/platform-lite/ {n++} END {print n+0}') -say record images "$images application images kept on the instance (#119)" +# A state file that cannot be written must not end the run: the report still +# has to go out. The cost of a lost write is one repeated mail. +write_state() { + if ! printf '%s\n' "$2" >"$STATE_DIR/$1.new" 2>/dev/null || + ! mv -f "$STATE_DIR/$1.new" "$STATE_DIR/$1" 2>/dev/null; then + echo "WARNING: could not write $STATE_DIR/$1 — the next run may repeat what this one sent" >&2 + fi +} -# --- the containers -------------------------------------------------------- -# `running/starting` is a deploy in progress, not an outage: the check runs on -# the hour and a deploy can land on it. -for name in platform-lite-app-1 platform-lite-caddy-1 postgres; do - state=$(docker inspect --format '{{.State.Status}}{{if .State.Health}}/{{.State.Health.Status}}{{end}}' "$name" 2>/dev/null || echo missing) - case "$state" in - running | running/healthy | running/starting) say record "container-$name" "$name: $state" ;; - *) say act "container-$name" "$name is $state" ;; - esac -done +is_count() { [[ ${1:-} =~ ^[0-9]+$ ]]; } -# --- the site, from here --------------------------------------------------- -# Through the proxy, as a visitor reaches it — but resolved to this machine, -# so the answer does not depend on the network hairpinning back in. Whether -# the site answers from OUTSIDE is watch.yml's question. -if [ -n "${SITE_ADDRESS:-}" ]; then +# The mail provider. The key goes to curl through a file descriptor: not in +# argv (/proc//cmdline is world-readable here), not in the environment of +# anything else this script starts, and not on a disk that may be full. +tem() { + curl -sS --fail-with-body --max-time 30 \ + -K <(printf 'header = "X-Auth-Token: %s"\n' "$EMAIL_API_KEY") "$@" +} + +load_env() { + # Only the variables this script uses, and none of them exported: the .env + # also holds the database password, the signing key and the bucket + # credentials, and a report has no business carrying those, nor its own mail + # key into every docker and journalctl it runs. + local line + while IFS= read -r line || [ -n "$line" ]; do + case "$line" in + EMAIL_API_KEY=* | EMAIL_PROJECT_ID=* | EMAIL_REGION=* | EMAIL_FROM=* | \ + EMAIL_FROM_NAME=* | OPS_EMAIL=* | SITE_ADDRESS=* | APP_ENV=*) + printf -v "${line%%=*}" '%s' "${line#*=}" + ;; + esac + done <"$ENV_FILE" + EMAIL_API_KEY=${EMAIL_API_KEY:-} + EMAIL_PROJECT_ID=${EMAIL_PROJECT_ID:-} + EMAIL_FROM=${EMAIL_FROM:-} + EMAIL_FROM_NAME=${EMAIL_FROM_NAME:-} + EMAIL_REGION=${EMAIL_REGION:-fr-par} + OPS_EMAIL=${OPS_EMAIL:-} + SITE_ADDRESS=${SITE_ADDRESS:-} + ENVIRONMENT=${APP_ENV:-unknown} +} + +check_disk() { + # The instance's one disk holds the images, the database, the journal and + # every preview. Full, it stops PostgreSQL writing — dev down, and every + # preview with it. + local used free + used=$(df --output=pcent / | tail -1 | tr -dc '0-9') + free=$(df -h --output=avail / | tail -1 | tr -d ' ') + if [ "$used" -ge 90 ]; then + say act disk "disk at ${used}%, ${free} free — when it fills, PostgreSQL stops writing and previews stop starting (#119)" + elif [ "$used" -ge 80 ]; then + say week disk "disk at ${used}%, ${free} free (#119)" + else + say record disk "disk at ${used}%, ${free} free" + fi +} + +check_docker() { + # Docker unreachable is itself the finding — and the reason every check + # after this one is skipped rather than reported as "missing" three times. + if ! timeout 20 docker info >/dev/null 2>&1; then + say act docker "Docker is not answering — the containers on this instance are in an unknown state" + return 1 + fi + local images name state + images=$(timeout 15 docker images --format '{{.Repository}}' 2>/dev/null | + awk '/platform-lite/ {n++} END {print n+0}') || images="an unknown number of" + say record images "$images application images kept on the instance (#119)" + for name in platform-lite-app-1 platform-lite-caddy-1 postgres; do + state=$(timeout 15 docker inspect \ + --format '{{.State.Status}}{{if .State.Health}}/{{.State.Health.Status}}{{end}}' \ + "$name" 2>/dev/null) || state=missing + case "$state" in + running | running/healthy | running/starting) say record "container-$name" "$name: $state" ;; + *) say act "container-$name" "$name is $state" ;; + esac + done + return 0 +} + +check_site() { + # Through the proxy, as a visitor reaches it — but resolved to this machine, + # so the answer does not depend on the network hairpinning back in. Whether + # the site answers from OUTSIDE is watch.yml's question. + [ -n "$SITE_ADDRESS" ] || return 0 + local code code=$(curl -s -o /dev/null -w '%{http_code}' --max-time 20 \ --resolve "$SITE_ADDRESS:443:127.0.0.1" "https://$SITE_ADDRESS/" || true) case "$code" in [1-4][0-9][0-9]) say record site "https://$SITE_ADDRESS/ answers $code" ;; *) say act site "https://$SITE_ADDRESS/ answers ${code:-nothing} from the instance itself" ;; esac -fi +} -# --- the nightly copy of the databases (#168) ------------------------------ -if [ ! -f "$BACKUP_RECORD" ]; then - say act backup "no copy of the databases has ever succeeded on this instance (#168)" -else +check_backup() { + if [ ! -f "$BACKUP_RECORD" ]; then + say act backup "no copy of the databases has ever succeeded on this instance (#168)" + return 0 + fi + local age_h age_h=$((($(date +%s) - $(stat -c %Y "$BACKUP_RECORD")) / 3600)) # 36 hours: a night can be late (the timer has five minutes of jitter and # catches up after a reboot), but two nights missed is a copy that stopped. if [ "$age_h" -gt 36 ]; then - say act backup "the newest copy of the databases is ${age_h} h old — the nightly copy has stopped (#168): $(cat "$BACKUP_RECORD")" + say act backup "the newest copy of the databases is ${age_h} h old — the nightly copy has stopped (#168)" else - say record backup "databases copied ${age_h} h ago: $(cat "$BACKUP_RECORD")" + say record backup "databases copied ${age_h} h ago ($(awk '{print $3}' "$BACKUP_RECORD") bytes)" fi -fi - -# --- preview copies nobody owns (#113) ------------------------------------- -orphans=0 -copies=0 -for db in $(docker exec postgres psql -U postgres -At -d postgres \ - -c "select datname from pg_database where datname like 'platform\_pr\_%'" 2>/dev/null || true); do - copies=$((copies + 1)) - [ -n "$(docker ps -a --filter "name=^pr-${db#platform_pr_}$" --format '{{.Names}}')" ] || - orphans=$((orphans + 1)) -done -if [ "$orphans" -gt 0 ]; then - say week previews "$orphans preview database(s) with no container — copies of dev's accounts; the next preview sweeps them, or docs/dev-environment.md" -else - say record previews "$copies preview database(s), each with its container" -fi +} -# --- what the application said in the last day ------------------------------ -# Read from the journal by container NAME, which compose keeps across a -# deploy — `docker logs` would only see the container started by the last one. -app_log() { - journalctl --quiet --no-pager --output=cat \ - CONTAINER_NAME=platform-lite-app-1 --since "24 hours ago" 2>/dev/null || true +check_previews() { + # Copies of dev's database that no preview container owns (#113). + local databases db copies=0 orphans=0 + if ! databases=$(timeout 15 docker exec postgres psql -U postgres -At -d postgres \ + -c "select datname from pg_database where datname like 'platform\_pr\_%'" 2>/dev/null); then + say week previews "PostgreSQL could not be asked which preview databases exist" + return 0 + fi + for db in $databases; do + copies=$((copies + 1)) + [ -n "$(timeout 15 docker ps -a --filter "name=^pr-${db#platform_pr_}$" --format '{{.Names}}' 2>/dev/null)" ] || + orphans=$((orphans + 1)) + done + if [ "$orphans" -gt 0 ]; then + say week previews "$orphans preview database(s) with no container — copies of dev's accounts; the next preview sweeps them, or docs/dev-environment.md" + else + say record previews "$copies preview database(s), each with its container" + fi } -log=$(app_log) -unrecorded=$(printf '%s\n' "$log" | - sed -n 's/^\[r360\] collector: \([0-9][0-9]*\) frame set(s) no record names.*/\1/p' | tail -1) -if [ -n "$unrecorded" ] && [ "$unrecorded" -gt 0 ]; then - say week collector "the R360 collector found $unrecorded frame set(s) that no record names and left them alone — a person decides (#156); the list: journalctl CONTAINER_NAME=platform-lite-app-1 | grep collector" -fi -collector_failed=$(printf '%s\n' "$log" | awk '/^\[r360\] collector: the (run|report) failed/ {n++} END {print n+0}') -[ "$collector_failed" -eq 0 ] || say week collector-failed "the R360 collector failed $collector_failed time(s)" -# Counts by kind, never the lines: a log line can carry an address or a path -# with a handle in it, and this report leaves the instance. -stalls=$(printf '%s\n' "$log" | awk '/^\[db\]/ {n++} END {print n+0}') -[ "$stalls" -eq 0 ] || say week db "$stalls database deadline(s) hit (#172) — which ones: journalctl CONTAINER_NAME=platform-lite-app-1 | grep '\[db\]'" -errors=$(printf '%s\n' "$log" | LC_ALL=C.UTF-8 awk '/⨯|Uncaught|Unhandled/ {n++} END {print n+0}') -if [ "$errors" -gt 0 ]; then - say week errors "$errors unhandled server error(s) — journalctl CONTAINER_NAME=platform-lite-app-1 --since '24 hours ago'" -else - say record errors "no unhandled server errors" -fi -# --- mail: what the provider did with ours (#22, #23) ----------------------- -headers=$(mktemp) -trap 'rm -f "$headers"' EXIT -chmod 600 "$headers" -tem() { - curl -sS --fail-with-body --max-time 30 -H @"$headers" "$@" +check_log() { + # One pass over the last day of the application's log, counting — never + # keeping a line. A log line can carry an address or a session token, and + # this report leaves the instance. Matched on a field journald sets itself + # (_SYSTEMD_UNIT) as well as the container's name, which compose keeps from + # one deploy to the next. + local counts lines unrecorded failed stalls errors + if ! counts=$(timeout 60 journalctl --no-pager --output=cat \ + _SYSTEMD_UNIT=docker.service CONTAINER_NAME=platform-lite-app-1 \ + --since "24 hours ago" 2>/dev/null | + LC_ALL=C.UTF-8 awk ' + { lines++ } + /^\[r360\] collector: [0-9]+ frame set\(s\) no record names/ { unrecorded = $3 + 0 } + /^\[r360\] collector: (the (run|report) failed|the schedule did not start|owner .* failed)/ { failed++ } + /^\[db\]/ { stalls++ } + /⨯|Uncaught|Unhandled/ { errors++ } + END { printf "%d %d %d %d %d\n", lines, unrecorded, failed, stalls, errors }'); then + say week log "the application's log could not be read from the journal — none of its counts are in this report" + return 0 + fi + read -r lines unrecorded failed stalls errors <<<"$counts" + if ! is_count "$lines" || ! is_count "$unrecorded" || ! is_count "$failed" || + ! is_count "$stalls" || ! is_count "$errors"; then + say week log "the application's log gave counts this script cannot read" + return 0 + fi + # An empty day is not a quiet day: the collector alone speaks every twelve + # hours. Zero lines from a container that has been up longer than that means + # the journal is not being read — permissions, a filter, a driver — and every + # "none" below would be a lie. + local started started_s + started=$(timeout 15 docker inspect --format '{{.State.StartedAt}}' platform-lite-app-1 2>/dev/null || true) + started_s=$(date -d "$started" +%s 2>/dev/null || date +%s) + if [ "$lines" -eq 0 ] && [ $(($(date +%s) - started_s)) -gt $((13 * 3600)) ]; then + say week log "the application's log is empty for a container up over 13 hours — it is not being read, so its counts are not in this report" + return 0 + fi + [ "$unrecorded" -eq 0 ] || + say week collector "the R360 collector found $unrecorded frame set(s) that no record names and left them alone — a person decides (#156); the list: journalctl CONTAINER_NAME=platform-lite-app-1 | grep collector" + [ "$failed" -eq 0 ] || say week collector-failed "the R360 collector failed $failed time(s)" + [ "$stalls" -eq 0 ] || say week db "$stalls database deadline(s) hit (#172)" + if [ "$errors" -gt 0 ]; then + say week errors "$errors unhandled server error(s) in 24 h" + else + say record errors "no unhandled server errors in 24 h ($lines log lines read)" + fi } -tem_base="https://api.scaleway.com/transactional-email/v1alpha1/regions/$EMAIL_REGION" -if [ -n "${EMAIL_API_KEY:-}" ] && [ -n "${EMAIL_PROJECT_ID:-}" ]; then - # Through a file, not argv: /proc//cmdline is world-readable here. - printf 'X-Auth-Token: %s\n' "$EMAIL_API_KEY" >"$headers" + +check_mail() { + # What the provider did with ours (#22, #23). Counts only — the provider's + # own console has the addresses, and that is where they stay. + [ -n "$EMAIL_API_KEY" ] && [ -n "$EMAIL_PROJECT_ID" ] || return 0 + local base="https://api.scaleway.com/transactional-email/v1alpha1/regions/$EMAIL_REGION" + local since stats parsed sent failed since=$(date -u -d '24 hours ago' +%Y-%m-%dT%H:%M:%SZ) - if stats=$(tem "$tem_base/statistics?project_id=$EMAIL_PROJECT_ID&since=$since"); then - read -r sent failed <<<"$(printf '%s' "$stats" | python3 -c 'import json,sys; d=json.load(sys.stdin); print(d.get("total_count",0), d.get("failed_count",0))' || true)" - sent=${sent:-0} - failed=${failed:-0} + if stats=$(tem "$base/statistics?project_id=$EMAIL_PROJECT_ID&since=$since" 2>/dev/null) && + parsed=$(printf '%s' "$stats" | python3 -c 'import json,sys; d=json.load(sys.stdin); print(int(d["total_count"]), int(d["failed_count"]))' 2>/dev/null) && + read -r sent failed <<<"$parsed" && is_count "$sent" && is_count "$failed"; then # A handful of failures in a small volume is a bad address; a quarter of # everything failing is the domain's reputation going, and the first sign # anyone else would notice is "I never got the e-mail". @@ -188,26 +277,36 @@ if [ -n "${EMAIL_API_KEY:-}" ] && [ -n "${EMAIL_PROJECT_ID:-}" ]; then else say week mail "the mail provider's statistics could not be read" fi - # The provider blocks an address after a hard bounce or a complaint. Only the - # count is read, and only a rise is news. - domain=$(tem "$tem_base/domains?project_id=$EMAIL_PROJECT_ID" 2>/dev/null | - python3 -c 'import json,sys; ds=json.load(sys.stdin).get("domains",[]); print(ds[0]["id"] if ds else "")' 2>/dev/null || true) - if [ -n "$domain" ]; then - blocked=$(tem "$tem_base/blocklists?domain_id=$domain&page_size=1" 2>/dev/null | - python3 -c 'import json,sys; print(json.load(sys.stdin).get("total_count",0))' 2>/dev/null || echo "") - before=$(cat "$STATE_DIR/blocked" 2>/dev/null || echo "") - if [ -n "$blocked" ]; then - if [ -n "$before" ] && [ "$blocked" -gt "$before" ]; then - say week blocked "the provider now blocks $blocked address(es), up from $before — a hard bounce or a complaint" - else - say record blocked "the provider blocks $blocked address(es)" - fi - printf '%s\n' "$blocked" >"$STATE_DIR/blocked" + + # The provider blocks an address after a hard bounce or a complaint. Only a + # rise is news, and only a count that was actually read may become the next + # run's baseline. + local domains domain response blocked before + if ! domains=$(tem "$base/domains?project_id=$EMAIL_PROJECT_ID" 2>/dev/null) || + ! domain=$(printf '%s' "$domains" | WANT="${EMAIL_FROM#*@}" python3 -c ' +import json, os, sys +for d in json.load(sys.stdin).get("domains", []): + if d.get("name") == os.environ["WANT"]: + print(d["id"]) + break' 2>/dev/null) || [ -z "$domain" ]; then + say week blocked "the provider's blocklist could not be read (no domain named ${EMAIL_FROM#*@})" + return 0 + fi + if response=$(tem "$base/blocklists?domain_id=$domain&page_size=1" 2>/dev/null) && + blocked=$(printf '%s' "$response" | python3 -c 'import json,sys; print(int(json.load(sys.stdin)["total_count"]))' 2>/dev/null) && + is_count "$blocked"; then + before=$(cat "$STATE_DIR/blocked" 2>/dev/null || true) + if is_count "$before" && [ "$blocked" -gt "$before" ]; then + say week blocked "the provider now blocks $blocked address(es), up from $before — a hard bounce or a complaint" + else + say record blocked "the provider blocks $blocked address(es)" fi + write_state blocked "$blocked" + else + say week blocked "the provider's blocklist could not be read" fi -fi +} -# --- the report -------------------------------------------------------------- report() { local line if [ ${#act[@]} -gt 0 ]; then @@ -225,79 +324,145 @@ report() { echo echo "Checked $(date -u +%Y-%m-%dT%H:%M:%SZ) on $(hostname). What each line means and what to do: docs/operations.md" } -body=$(report) -# The journal always gets the whole report, mailed or not. -printf '%s\n' "$body" +# send : 0 sent, 1 failed, 2 there is nowhere to send it. +# +# Called from `||` and `case`, where bash switches `set -e` off for the whole +# function — so nothing in here relies on it: every step that can fail says +# what happens next itself. (The first version relied on it, and a mail the +# provider refused was recorded as sent.) send() { - local subject=$1 - if [ -z "${OPS_EMAIL:-}" ]; then + local subject=$1 payload response + if [ -z "$OPS_EMAIL" ]; then echo "OPS_EMAIL is not set: \"$subject\" reached this journal and nobody else" - return 0 + return 2 fi - if [ -z "${EMAIL_API_KEY:-}" ] || [ -z "${EMAIL_PROJECT_ID:-}" ] || [ -z "${EMAIL_FROM:-}" ]; then + if [ -z "$EMAIL_API_KEY" ] || [ -z "$EMAIL_PROJECT_ID" ] || [ -z "$EMAIL_FROM" ]; then echo "the mail provider is not configured in $ENV_FILE: \"$subject\" was not sent" >&2 return 1 fi - local payload - payload=$(SUBJECT="$subject" BODY="$body" python3 -c ' + payload=$(SUBJECT="$subject" BODY="$body" FROM="$EMAIL_FROM" FROM_NAME="$EMAIL_FROM_NAME" \ + PROJECT="$EMAIL_PROJECT_ID" TO="$OPS_EMAIL" python3 -c ' import json, os -sender = {"email": os.environ["EMAIL_FROM"]} -if os.environ.get("EMAIL_FROM_NAME"): - sender["name"] = os.environ["EMAIL_FROM_NAME"] +sender = {"email": os.environ["FROM"]} +if os.environ["FROM_NAME"]: + sender["name"] = os.environ["FROM_NAME"] print(json.dumps({ - "project_id": os.environ["EMAIL_PROJECT_ID"], + "project_id": os.environ["PROJECT"], "from": sender, - "to": [{"email": os.environ["OPS_EMAIL"]}], + "to": [{"email": os.environ["TO"]}], "subject": os.environ["SUBJECT"], "text": os.environ["BODY"], -}))') - tem -H 'Content-Type: application/json' --data-binary "$payload" "$tem_base/emails" >/dev/null +}))') || { + echo "the report could not be put into a message: \"$subject\" was not sent" >&2 + return 1 + } + if ! response=$(printf '%s' "$payload" | tem -H 'Content-Type: application/json' \ + --data-binary @- "https://api.scaleway.com/transactional-email/v1alpha1/regions/$EMAIL_REGION/emails" 2>&1); then + echo "the provider did not take \"$subject\": ${response:0:300}" >&2 + return 1 + fi echo "mailed: $subject" + return 0 } -# What was last mailed as ACT NOW, as condition keys — so an alert goes out -# when the SET of problems changes, not when a number inside one does. -now_keys=$(printf '%s\n' "${act_keys[@]}" | sort -u | tr '\n' ' ') -now_keys=${now_keys% } -last_keys=$(sed -n 1p "$STATE_DIR/act" 2>/dev/null || true) -last_sent=$(sed -n 2p "$STATE_DIR/act" 2>/dev/null || echo 0) -now=$(date +%s) -status=0 +main() { + load_env + mkdir -p "$STATE_DIR" 2>/dev/null || echo "WARNING: $STATE_DIR could not be created" >&2 -if [ -n "$now_keys" ]; then - if [ "$now_keys" != "$last_keys" ] || [ $((now - last_sent)) -ge 86400 ]; then - if send "[$ENVIRONMENT] ACT NOW: ${act[0]}"; then - printf '%s\n%s\n' "$now_keys" "$now" >"$STATE_DIR/act" - else - status=1 + local key + while read -r key; do + [ -z "$key" ] || was_seen[$key]=1 + done < <(cat "$STATE_DIR/seen" 2>/dev/null || true) + + check_disk + if check_docker; then + check_previews + check_log + fi + check_site + check_backup + check_mail + + body=$(report) + # The journal always gets the whole report, mailed or not. + printf '%s\n' "$body" + write_state seen "$(printf '%s\n' "${now_seen[@]}")" + + local now status=0 rc + now=$(date +%s) + + # What was mailed as ACT NOW, and when, per condition. A condition is mailed + # when it is new or was last mailed a day ago; a condition that has stopped + # is mailed once as resolved. Recorded only when the mail actually went. + declare -A mailed=() + local k t + while read -r k t; do + [ -n "$k" ] && is_count "$t" && mailed[$k]=$t + done < <(cat "$STATE_DIR/act" 2>/dev/null || true) + + local fresh=() gone=() + for k in "${act_keys[@]}"; do + if [ -z "${mailed[$k]:-}" ] || [ $((now - mailed[$k])) -ge 86400 ]; then + fresh+=("$k") fi + done + for k in "${!mailed[@]}"; do + [ -n "${act_line[$k]:-}" ] || gone+=("$k") + done + + local changed=false subject + if [ ${#fresh[@]} -gt 0 ]; then + # Named after what is NEW, not whatever check happens to run first — a + # backup that stops while the disk alert is standing must not arrive + # looking like the disk alert again. + subject="[$ENVIRONMENT] ACT NOW: ${act_line[${fresh[0]}]}" + [ ${#fresh[@]} -eq 1 ] || subject="$subject (and $((${#fresh[@]} - 1)) more)" + rc=0 + send "$subject" || rc=$? + case $rc in + 0) for k in "${fresh[@]}"; do mailed[$k]=$now; done && changed=true ;; + 1) status=1 ;; + esac fi -elif [ -n "$last_keys" ]; then - if send "[$ENVIRONMENT] resolved: $last_keys"; then - rm -f "$STATE_DIR/act" - else - status=1 + if [ ${#gone[@]} -gt 0 ]; then + rc=0 + send "[$ENVIRONMENT] resolved: ${gone[*]}" || rc=$? + case $rc in + 0 | 2) for k in "${gone[@]}"; do unset "mailed[$k]"; done && changed=true ;; + 1) status=1 ;; + esac fi -fi - -# Once a day whatever the state: the report that says "nothing to do" is what -# makes an empty inbox mean something. Its absence by breakfast is itself the -# signal — the instance, the timer or the mail path is broken. -today=$(date -u +%F) -if [ "$(date -u +%H)" = "$DIGEST_HOUR_UTC" ] && [ "$(cat "$STATE_DIR/digest-day" 2>/dev/null || true)" != "$today" ]; then - if [ ${#act[@]} -gt 0 ]; then - summary="${#act[@]} to act on" - elif [ ${#week[@]} -gt 0 ]; then - summary="${#week[@]} to look at this week" - else - summary="nothing to do" + if [ "$changed" = true ]; then + local lines="" + for k in "${!mailed[@]}"; do lines+="$k ${mailed[$k]}"$'\n'; done + write_state act "${lines%$'\n'}" fi - if send "[$ENVIRONMENT] daily: $summary"; then - printf '%s\n' "$today" >"$STATE_DIR/digest-day" - else - status=1 + + # Once a day whatever the state: the report that says "nothing to do" is what + # makes an empty inbox mean something. Its absence by breakfast is itself the + # signal — the instance, the timer or the mail path is broken. + local today summary + today=$(date -u +%F) + if [ $((10#$(date -u +%H))) -ge $((10#$DIGEST_HOUR_UTC)) ] && + [ "$(cat "$STATE_DIR/digest-day" 2>/dev/null || true)" != "$today" ]; then + if [ ${#act[@]} -gt 0 ]; then + summary="${#act[@]} to act on" + elif [ ${#week[@]} -gt 0 ]; then + summary="${#week[@]} to look at this week" + else + summary="nothing to do" + fi + rc=0 + send "[$ENVIRONMENT] daily: $summary" || rc=$? + case $rc in + 0) write_state digest-day "$today" ;; + 1) status=1 ;; + esac fi -fi -exit "$status" + return "$status" +} + +main "$@" +exit $? diff --git a/deploy/remote-deploy.sh b/deploy/remote-deploy.sh index 1644019..d4a952c 100644 --- a/deploy/remote-deploy.sh +++ b/deploy/remote-deploy.sh @@ -158,7 +158,10 @@ install_ops_timer() ( cat >"$units/platform-ops.service" <<'UNIT' [Unit] Description=Look at this instance and tell a person what needs a decision (#167) -Requires=docker.service +# Wants, not Requires: with Requires a failed Docker would stop this check from +# starting at all — and "Docker is not answering" is one of the things it is +# there to say. +Wants=docker.service After=docker.service [Service] @@ -169,7 +172,20 @@ User=ubuntu SupplementaryGroups=systemd-journal StateDirectory=platform-ops PrivateTmp=true -TimeoutStartSec=300 +# Every call in the script has its own limit; this is the sum of them with room +# to spare, so a run is ended by its own time-outs, which report, and not by +# systemd, which does not. +TimeoutStartSec=600 +# One core, no swap: a check must never be the process the OOM killer weighs +# against PostgreSQL. +MemoryMax=128M +# It reads, and writes only its own state. Nothing in it needs to become +# anyone else — the account has passwordless sudo, and this closes that path. +NoNewPrivileges=yes +ProtectSystem=strict +ProtectHome=read-only +PrivateDevices=yes +RestrictSUIDSGID=yes ExecStart=/bin/bash /opt/platform-lite/ops-check.sh UNIT cat >"$units/platform-ops.timer" <<'UNIT' @@ -185,12 +201,26 @@ RandomizedDelaySec=120 WantedBy=timers.target UNIT # The journal is where the application's log now lives, so it is also what -# could fill the disk being watched. Capped here rather than left to journald's -# default, which is a tenth of the filesystem. +# could fill the disk being watched — and application log lines can carry an +# address or a session token, so how long they stay is a data question as much +# as a disk one. Capped at 300 MB and two weeks. MaxFileSec makes the two weeks +# true: journald deletes whole files, and at dev's volume a file otherwise +# covers a month. SystemKeepFree is set because the default is 15% of the disk, +# which a disk at 92% already breaks, and journald would then keep almost +# nothing. cat >"$units/platform-lite.conf" <<'UNIT' [Journal] SystemMaxUse=300M -MaxRetentionSec=30day +SystemKeepFree=500M +MaxFileSec=1day +MaxRetentionSec=14day +UNIT +# Ubuntu forwards the journal to rsyslog, which would keep a second copy of +# every application line in /var/log/syslog — rotated weekly for a month and +# capped by nothing. The containers log under a tag (compose.yaml), and lines +# with that tag stop here. Only those: auth.log and the rest are untouched. +cat >"$units/10-platform-lite.conf" <<'UNIT' +if $programname startswith 'platform-lite-' then stop UNIT units_changed=false for unit in platform-ops.service platform-ops.timer; do @@ -208,7 +238,12 @@ UNIT sudo install -d -m 755 /etc/systemd/journald.conf.d sudo install -m 644 "$units/platform-lite.conf" /etc/systemd/journald.conf.d/platform-lite.conf sudo systemctl restart systemd-journald - echo "journal: capped at 300M" + echo "journal: capped at 300M and two weeks" + fi + if [ -d /etc/rsyslog.d ] && ! cmp -s "$units/10-platform-lite.conf" /etc/rsyslog.d/10-platform-lite.conf; then + sudo install -m 644 "$units/10-platform-lite.conf" /etc/rsyslog.d/10-platform-lite.conf + sudo systemctl restart rsyslog + echo "syslog: application lines kept out of /var/log/syslog" fi ) set +e diff --git a/docs/operations.md b/docs/operations.md index dd21437..0d82691 100644 --- a/docs/operations.md +++ b/docs/operations.md @@ -38,8 +38,12 @@ At most three, because a channel that says everything is a channel nobody reads — which is the failure this document exists to prevent, one level up. - **ACT NOW** — mailed within the hour it starts, again if still true a day - later, and once more when it stops (`[dev] resolved: …`). A number changing - inside the same problem (disk 91% → 92%) does not send another. + later, and once more, per condition, when it stops (`[dev] resolved: …`). A + number changing inside the same problem (disk 91% → 92%) does not send + another; a NEW problem while one is standing is named in the subject. + Conditions one bad look can produce on one core — the site not answering, a + container missing, Docker not answering — need two hourly looks in a row: the + first appears under THIS WEEK as "seen once". - **THIS WEEK** — in the daily report. - **RECORD** — in the daily report, so a figure has a history to compare with. @@ -58,7 +62,7 @@ reads — which is the failure this document exists to prevent, one level up. | The R360 collector found frame sets no record names | this week | By design it deletes nothing it cannot account for, and waits for a person (#156). The list is in the log: `journalctl CONTAINER_NAME=platform-lite-app-1 \| grep collector`. Decide per set; nothing is lost by waiting a week. | | The R360 collector failed | this week | The same log. A sweep that stops reporting is worse than one that fails loudly — this is the loud version. | | Database deadlines hit | this week | #172. Which bound and which path are in the log (`grep '\[db\]'`); one a day is noise, a pattern is a query or a lock to look at. | -| Unhandled server errors | this week | The log for the last day. | +| Unhandled server errors | this week | The log for the last day — read it on the instance, and see "Logs" below before copying a line anywhere. | | A quarter or more of mail failed (4+ sent) | ACT NOW | The sending domain's reputation or the provider — people are not receiving verification messages. Scaleway console → Transactional Email; SPF/DKIM/DMARC per G8. | | Some mail failed | this week | A bounce or a rejection — usually one bad address. | | The provider blocks more addresses than yesterday | this week | A hard bounce or a complaint. The addresses are in the Scaleway console, deliberately not in the report. | @@ -92,7 +96,8 @@ journalctl -u platform-ops.service -n 40 --no-pager To try the outside alarm without breaking dev, run the `Watch` workflow by hand with an address that cannot answer (`https://down.invalid/`): it opens an -`outage` issue. The next scheduled run against dev closes it again. +issue labelled `outage-drill` — never `outage`, so a drill cannot open or close +dev's real alarm. Run it again with an address that answers to close it. ## Logs @@ -100,9 +105,11 @@ The application's and the proxy's logs go to the host's journal (`deploy/compose.yaml`), not to a file inside the container's directory. That file is deleted with the container, which is every deploy — so until #167 the log of the hour before a bad deploy was gone by the time anyone -looked for it. The journal is capped at 300 MB and thirty days -(`/etc/systemd/journald.conf.d/platform-lite.conf`), and every entry carries -the container's name, which compose keeps across deploys: +looked for it. The journal is capped at 300 MB and two weeks +(`/etc/systemd/journald.conf.d/platform-lite.conf`; one file a day, so the two +weeks are real), the lines are kept out of `/var/log/syslog` +(`/etc/rsyslog.d/10-platform-lite.conf`), and every entry carries the +container's name, which compose keeps across deploys: ``` journalctl CONTAINER_NAME=platform-lite-app-1 --since "2 hours ago" @@ -111,6 +118,12 @@ journalctl CONTAINER_NAME=platform-lite-app-1 --since "2 hours ago" Preview containers keep Docker's file log, capped at three 10 MB files: they are throwaway, and their log goes with them on purpose. +**Never paste a log line into an issue, a pull request or a chat.** A failed +database query is logged with its parameters, and those can be an e-mail +address or a live session token; this repository is public. Describe what the +line says, or redact it first. That the lines carry parameters at all is its +own task (#186), and until it is done this rule is the whole defence. + ## What is not covered yet Said here so that silence about them is not read as "checked": @@ -125,6 +138,11 @@ Said here so that silence about them is not read as "checked": disables them in a repository with no activity for sixty days. The daily report cannot see whether `watch.yml` ran. If the repository goes quiet for two months, re-enable the workflow in the Actions tab. +- **Log lines carry query parameters.** Drizzle wraps a failed query with + its parameters and Better Auth logs that error whole, so an address or a + session token can reach the journal. Two weeks of retention bounds it; it + does not remove it, and the journal cannot forget one account (#34). Redacting + at the source is #186. - **Shipping logs somewhere else** was considered and not done: it means a new provider, a recurring cost, and log lines that can carry personal data leaving the EU (§7). The instance speaking for itself covers the need today.