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..e336b3c 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -296,6 +296,33 @@ 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 + 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: | + # 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 # 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 +518,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..6b3715d --- /dev/null +++ b/.github/workflows/watch.yml @@ -0,0 +1,112 @@ +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: "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: + 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/' }} + # 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: | + # 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 --proto '=https' --url "$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 }} + # 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 "$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 ;; + *) up=false ;; + esac + + if [ "$up" = false ] && [ -z "$open" ]; then + gh label create "$LABEL" --color B60205 \ + --description "The site is not answering (opened and closed by .github/workflows/watch.yml)" \ + --force >/dev/null + issue=$(gh issue create --label "$LABEL" \ + --title "$URL is not answering" \ + --body "$(printf '%s\n' \ + "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, \"What each signal means\". This issue closes itself when the site answers again." \ + "" \ + "@$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\`)." || true + gh issue close "$open" + else + echo "nothing changed: up=$up, open $LABEL 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..80a953e 100644 --- a/deploy/compose.yaml +++ b/deploy/compose.yaml @@ -18,6 +18,19 @@ 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 + # 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 @@ -45,6 +58,11 @@ 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 + 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 new file mode 100644 index 0000000..afeb731 --- /dev/null +++ b/deploy/ops-check.sh @@ -0,0 +1,468 @@ +#!/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, per condition, 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. +# +# 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. 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} +# 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. +say() { + local tier=$1 key=$2 + shift 2 + case "$tier" in + 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 +} + +# 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 +} + +is_count() { [[ ${1:-} =~ ^[0-9]+$ ]]; } + +# 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 +} + +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)" + else + say record backup "databases copied ${age_h} h ago ($(awk '{print $3}' "$BACKUP_RECORD") bytes)" + fi +} + +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 +} + +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 +} + +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 "$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". + 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 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 +} + +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" +} + +# 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 payload response + if [ -z "$OPS_EMAIL" ]; then + echo "OPS_EMAIL is not set: \"$subject\" reached this journal and nobody else" + return 2 + 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 + 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["FROM"]} +if os.environ["FROM_NAME"]: + sender["name"] = os.environ["FROM_NAME"] +print(json.dumps({ + "project_id": os.environ["PROJECT"], + "from": sender, + "to": [{"email": os.environ["TO"]}], + "subject": os.environ["SUBJECT"], + "text": os.environ["BODY"], +}))') || { + 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 +} + +main() { + load_env + mkdir -p "$STATE_DIR" 2>/dev/null || echo "WARNING: $STATE_DIR could not be created" >&2 + + 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 + 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 + if [ "$changed" = true ]; then + local lines="" + for k in "${!mailed[@]}"; do lines+="$k ${mailed[$k]}"$'\n'; done + write_state act "${lines%$'\n'}" + 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. + 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 + + return "$status" +} + +main "$@" +exit $? 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..d4a952c 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,114 @@ 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) +# 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] +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 +# 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' +[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 — 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 +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 + 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 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 +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..0d82691 --- /dev/null +++ b/docs/operations.md @@ -0,0 +1,148 @@ +# 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, 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. + +## 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 — 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. | + +## 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 +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 + +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 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" +``` + +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": + +- **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. +- **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. 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