From 7a93c60e9dcdbbd194afe3491e5f9ec1f753a23f Mon Sep 17 00:00:00 2001 From: Adamskiee Date: Fri, 7 Aug 2026 12:47:51 +0800 Subject: [PATCH] feat(deploy-status): add lightweight offline observability --- CLAUDE.md | 1 + GSM-module/GSM-fastapi/main.py | 10 +- deploy/config/nginx.prod.conf | 2 + deploy/config/status.env.example | 9 ++ deploy/config/status.html | 8 ++ deploy/scripts/collect-status.py | 151 +++++++++++++++++++++++ deploy/scripts/install.sh | 6 +- deploy/scripts/lib/deploy-common.sh | 44 ++++++- deploy/scripts/lib/retention.sh | 6 + deploy/scripts/upgrade.sh | 9 +- deploy/tests/pytest.ini | 3 + deploy/tests/test_collect_status.py | 59 +++++++++ docker-compose.prod.yml | 22 +++- docs/deployment/monitoring-logging.md | 71 +++-------- scripts/build-bundle.sh | 2 +- server/Dockerfile | 6 +- server/app/logging_config.py | 38 ++++++ server/app/main.py | 26 +--- server/app/tests/test_logging_config.py | 27 ++++ server/app/tests/test_status_contract.py | 22 ++++ 20 files changed, 434 insertions(+), 88 deletions(-) create mode 100644 deploy/config/status.env.example create mode 100644 deploy/config/status.html create mode 100644 deploy/scripts/collect-status.py create mode 100644 deploy/tests/pytest.ini create mode 100644 deploy/tests/test_collect_status.py create mode 100644 server/app/logging_config.py create mode 100644 server/app/tests/test_logging_config.py create mode 100644 server/app/tests/test_status_contract.py diff --git a/CLAUDE.md b/CLAUDE.md index 5772d520..478f4b1f 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -61,6 +61,7 @@ Run for each component actually touched — don't assume one component's green b | `mobile-app/sapot-mobile-app/` | `pnpm run testAll` (= test + typecheck + lint + expo-doctor), or the individual `pnpm test` / `pnpm run typecheck` / `pnpm run lint` | | `admin-frontend/sapot-admin/` | `pnpm run lint && pnpm run build` — **no test script exists in this component**; don't claim test coverage that isn't there | | `GSM-module/` | No automated tests exist — verify manually per `docs/getting-started/gsm-module-setup.md` | +| `deploy/scripts/collect-status.py` | `python3 -m pytest tests` — **run from `deploy/`**. No CI job runs this; it is manual per CLAUDE.md's process. | If the change is release-relevant (server), `server/app/version.py` must match the git tag per `VERSIONING.md` before tagging — not typically a per-commit concern, but relevant if asked to prepare a release. diff --git a/GSM-module/GSM-fastapi/main.py b/GSM-module/GSM-fastapi/main.py index f038c5f6..326dbdc6 100644 --- a/GSM-module/GSM-fastapi/main.py +++ b/GSM-module/GSM-fastapi/main.py @@ -13,7 +13,9 @@ """ import logging +import os import sys +from logging.handlers import RotatingFileHandler import uvicorn @@ -23,12 +25,18 @@ def setup_logging(): level = getattr(logging, settings.log_level.upper(), logging.INFO) fmt = "%(asctime)s [%(levelname)-8s] %(name)s: %(message)s" + log_dir = os.environ.get("GSM_LOG_DIR", ".") + os.makedirs(log_dir, exist_ok=True) + file_handler = RotatingFileHandler( + os.path.join(log_dir, "sapot.log"), maxBytes=10**6, + backupCount=3, encoding="utf-8", + ) logging.basicConfig( level=level, format=fmt, handlers=[ logging.StreamHandler(sys.stdout), - logging.FileHandler("sapot.log", encoding="utf-8"), + file_handler, ], ) # Quiet down uvicorn's access log a little diff --git a/deploy/config/nginx.prod.conf b/deploy/config/nginx.prod.conf index 80a80688..0a6f950a 100644 --- a/deploy/config/nginx.prod.conf +++ b/deploy/config/nginx.prod.conf @@ -6,6 +6,8 @@ server { ssl_certificate_key /certs/server.key; ssl_protocols TLSv1.2 TLSv1.3; ssl_ciphers HIGH:!aNULL:!MD5; + location = /status { alias /usr/share/nginx/status/status.html; } + location = /status/health.json { alias /usr/share/nginx/state/health.json; add_header Cache-Control no-store; } location /static/ { alias /usr/share/nginx/static/; autoindex off; expires 30d; add_header Cache-Control "public, immutable"; } location /tiles/ { proxy_pass http://tileserver:8080/; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; proxy_set_header X-Forwarded-Path /tiles; gzip on; gzip_types application/json; gzip_min_length 256; } location ~ ^/(data|fonts|sprites)/ { proxy_pass http://tileserver:8080; proxy_set_header Host $host; proxy_set_header X-Forwarded-Proto $scheme; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; } diff --git a/deploy/config/status.env.example b/deploy/config/status.env.example new file mode 100644 index 00000000..115c6b25 --- /dev/null +++ b/deploy/config/status.env.example @@ -0,0 +1,9 @@ +# Read-only status collector credentials. This placeholder is intentionally +# distinct from __GENERATE__, which substitutes the shared application secret. +STATUS_DATABASE_URL=mysql+pymysql://sapot_status:__STATUS_DB_PASSWORD__@db:3306/sapot +STATUS_REDIS_URL=redis://redis:6379 +STATUS_OUTPUT_DIR=/status +STATUS_CERT_PATH=/certs/server.crt +STATUS_INTEGRITY_PATH=/status/integrity.json +STATUS_INTERVAL_SECONDS=60 +STATUS_PROBE_TIMEOUT=5 diff --git a/deploy/config/status.html b/deploy/config/status.html new file mode 100644 index 00000000..dd64c63b --- /dev/null +++ b/deploy/config/status.html @@ -0,0 +1,8 @@ +SAPOT status + +

SAPOT status

Loading...

+ diff --git a/deploy/scripts/collect-status.py b/deploy/scripts/collect-status.py new file mode 100644 index 00000000..209820c4 --- /dev/null +++ b/deploy/scripts/collect-status.py @@ -0,0 +1,151 @@ +#!/usr/bin/env python3 +"""Write a LAN-only, static status snapshot without using Docker's API.""" +import argparse +import json +import os +import socket +import sys +import time +import urllib.error +import urllib.request +from dataclasses import dataclass, field +from datetime import datetime, timedelta, timezone + +PRESENCE_KEY = "ws:online_users" +TEMP_NAME = ".health.json.tmp" +OUTPUT_NAME = "health.json" +DEFAULT_SERVICE_URLS = {"api": "http://api:8000/version", "admin": "http://admin:3000", "tileserver": "http://tileserver:8080", "gsm": "http://gsm-fastapi:8001/health"} + + +@dataclass +class Config: + output_dir: str + cert_path: str + integrity_path: str + database_url: str + redis_url: str + probe_timeout: float + interval_seconds: int + service_urls: dict = field(default_factory=lambda: dict(DEFAULT_SERVICE_URLS)) + + +def config_from_env() -> Config: + database_url = os.environ.get("STATUS_DATABASE_URL") + if not database_url: + raise SystemExit("STATUS_DATABASE_URL is not set; refusing to start") + output_dir = os.environ.get("STATUS_OUTPUT_DIR", "/status") + return Config(output_dir, os.environ.get("STATUS_CERT_PATH", "/certs/server.crt"), os.environ.get("STATUS_INTEGRITY_PATH", os.path.join(output_dir, "integrity.json")), database_url, os.environ.get("STATUS_REDIS_URL", "redis://redis:6379"), float(os.environ.get("STATUS_PROBE_TIMEOUT", "5")), int(os.environ.get("STATUS_INTERVAL_SECONDS", "60"))) + + +def probe_http(url: str, timeout: float) -> tuple[bool, str]: + try: + with urllib.request.urlopen(url, timeout=timeout) as response: + code, body = response.status, response.read(4096) + return code < 500, f"HTTP {code}|{body.decode('utf-8', 'replace')[:200]}" + except urllib.error.HTTPError as error: + return error.code < 500, f"HTTP {error.code}" + except (urllib.error.URLError, socket.timeout, OSError) as error: + return False, f"unreachable: {error}" + except Exception as error: + return False, f"probe error: {error}" + + +def collect_checks(config: Config): + checks, version = [], None + for name, url in config.service_urls.items(): + ok, detail = probe_http(url, config.probe_timeout) + if name == "api" and ok: + try: version = json.loads(detail.split("|", 1)[1]).get("version") + except Exception: pass + checks.append({"check": name, "status": "PASS" if ok else "FAIL", "detail": ("reachable" if name in {"admin", "tileserver"} else "responding") if ok else detail.split("|", 1)[0]}) + return checks, version + + +def count_online_devices(config: Config): + try: + import redis + return int(redis.from_url(config.redis_url, socket_timeout=config.probe_timeout).zcount(PRESENCE_KEY, time.time(), "+inf")) + except Exception: return None + + +def query_db_counters(config: Config): + counters = {"messagesLastHour": None, "mutatingRequestsLastHour": None, "mutatingErrorRatePct": None, "gsmSmsPending": None} + try: + from sqlalchemy import create_engine, text + engine = create_engine(config.database_url, pool_pre_ping=True, connect_args={"connect_timeout": int(config.probe_timeout)}) + with engine.connect() as con: + try: counters["messagesLastHour"] = con.execute(text("SELECT COUNT(*) FROM message WHERE created_at > :cutoff"), {"cutoff": int(time.time() * 1000) - 3600000}).scalar() + except Exception: pass + try: + row = con.execute(text("SELECT COUNT(*) total, SUM(CASE WHEN JSON_EXTRACT(metadata_json, '$.status_code') >= 500 THEN 1 ELSE 0 END) errors FROM activity_logs WHERE created_at > :cutoff"), {"cutoff": (datetime.now(timezone.utc) - timedelta(hours=1)).replace(tzinfo=None)}).one() + total, errors = int(row.total or 0), int(row.errors or 0) + counters["mutatingRequestsLastHour"] = total + counters["mutatingErrorRatePct"] = round(errors / total * 100, 2) if total else 0.0 + except Exception: pass + try: counters["gsmSmsPending"] = con.execute(text("SELECT COUNT(*) FROM sms_log WHERE status = 'pending'")).scalar() + except Exception: pass + except Exception: pass + return counters + + +def disk_free_bytes(path): + try: + stat = os.statvfs(path); return int(stat.f_bavail * stat.f_frsize) + except Exception: return None + + +def cert_expires_in_days(path): + try: + from cryptography import x509 + with open(path, "rb") as f: cert = x509.load_pem_x509_certificate(f.read()) + return int((cert.not_valid_after_utc - datetime.now(timezone.utc)).total_seconds() // 86400) + except Exception: return None + + +def read_integrity(path): + try: + with open(path, encoding="utf-8") as f: result = json.load(f) + return {"status": result["status"], "verifiedAt": result.get("verifiedAt")} if isinstance(result, dict) and "status" in result else None + except Exception: return None + + +def overall_status(checks): + if not checks: return "unknown" + states = {check["check"]: check["status"] for check in checks} + if states.get("api") != "PASS": return "failed" + return "degraded" if any(v != "PASS" for v in states.values()) else "healthy" + + +def build_payload(checks, counters, integrity, version, generated_at, collector_age_seconds): + return {"generatedAt": generated_at.strftime("%Y-%m-%dT%H:%M:%SZ"), "collectorAgeSeconds": collector_age_seconds, "version": version, "overall": overall_status(checks), "checks": checks, "counters": counters, "integrity": integrity or {"status": "UNKNOWN", "verifiedAt": None}} + + +def write_atomic(output_dir, payload): + os.makedirs(output_dir, exist_ok=True) + temp = os.path.join(output_dir, TEMP_NAME) + with open(temp, "w", encoding="utf-8") as f: + json.dump(payload, f, indent=2); f.write("\n"); f.flush(); os.fsync(f.fileno()) + os.replace(temp, os.path.join(output_dir, OUTPUT_NAME)) + + +def run_once(config): + started = datetime.now(timezone.utc) + try: + checks, version = collect_checks(config) + counters = query_db_counters(config) + counters.update({"devicesConnected": count_online_devices(config), "diskFreeBytes": disk_free_bytes(config.output_dir), "certExpiresInDays": cert_expires_in_days(config.cert_path)}) + payload = build_payload(checks, counters, read_integrity(config.integrity_path), version, started, int((datetime.now(timezone.utc) - started).total_seconds())) + except Exception as error: + payload = {"generatedAt": started.strftime("%Y-%m-%dT%H:%M:%SZ"), "collectorAgeSeconds": 0, "version": None, "overall": "unknown", "reason": f"collector cycle failed: {error}", "checks": [], "counters": {}, "integrity": {"status": "UNKNOWN", "verifiedAt": None}} + try: write_atomic(config.output_dir, payload) + except Exception as error: print(f"collect-status: could not write output: {error}", file=sys.stderr, flush=True) + return payload + + +def main(): + parser = argparse.ArgumentParser(); parser.add_argument("--once", action="store_true"); args = parser.parse_args(); config = config_from_env() + if args.once: print(json.dumps(run_once(config), indent=2)); return 0 + while True: run_once(config); time.sleep(config.interval_seconds) + + +if __name__ == "__main__": raise SystemExit(main()) diff --git a/deploy/scripts/install.sh b/deploy/scripts/install.sh index ea7459d0..1c3d96c9 100755 --- a/deploy/scripts/install.sh +++ b/deploy/scripts/install.sh @@ -8,21 +8,25 @@ if [ -L "$SAPOT_ROOT/releases/current" ] || [ -e "$SAPOT_ROOT/releases/current" current=$(manifest_value "$(readlink -f "$SAPOT_ROOT/releases/current")/manifest.json" version) log_error "already installed (v$current) - use upgrade.sh instead"; exit 1 fi -verify_checksums "$source_release" || { log_error "bundle checksum verification failed"; exit 1; } +if verify_checksums "$source_release"; then integrity_status=PASS; else integrity_status=FAIL; log_error "bundle checksum verification failed"; exit 1; fi disk_preflight "$(manifest_value "$source_manifest" requiredDiskBytes)" target="$SAPOT_ROOT/releases/v$version"; mkdir -p "$SAPOT_ROOT/releases" [ ! -e "$target" ] && cp -a "$source_release" "$target" prepare_env_files "$target" +write_integrity "$integrity_status" ip=$($target/certs/detect-ip.sh 2>/dev/null || true) [ -n "$ip" ] || { read -r -p "LAN IP for TLS certificate: " ip; } CERT_DIR="$SAPOT_ROOT/shared/certs" CERT_CN="$ip" CERT_SAN="IP:$ip,DNS:localhost" "$target/certs/gen-certs.sh" read -r -p "Is the GSM Arduino connected at $(grep '^GSM_ARDUINO_PORT=' "$SAPOT_ROOT/shared/gsm-arduino.env" | cut -d= -f2)? [y/N] " answer hardware=false; [[ "$answer" =~ ^[Yy]$ ]] && hardware=true for image in "$target"/images/*.tar; do docker load -i "$image"; done +prepare_shared_dirs "$VERIFY_DIGESTS" "$target/manifest.json" compose "$target" up -d db redis; wait_healthy "$target" db; wait_healthy "$target" redis compose "$target" run --rm api alembic upgrade head compose "$target" up -d; for _ in {1..36}; do curl -kfs https://localhost/version >/dev/null 2>&1 && break; sleep 5; done curl -kfsS https://localhost/version >/dev/null || { log_error "nginx/api did not become ready"; exit 1; } +provision_status_db_user "$target" +compose "$target" run --rm --no-deps status-collector --once >/dev/null 2>&1 || log_error "initial status collection failed; /status will populate within one interval" ln -sfn "$target" "$SAPOT_ROOT/releases/current"; write_state install "" "$version" "$hardware" "$SELF/lib/retention.sh"; log_pass "installed SAPOT v$version" diff --git a/deploy/scripts/lib/deploy-common.sh b/deploy/scripts/lib/deploy-common.sh index f4594b3f..bac48ba4 100755 --- a/deploy/scripts/lib/deploy-common.sh +++ b/deploy/scripts/lib/deploy-common.sh @@ -66,14 +66,50 @@ os.replace(tmp,path) PY } prepare_env_files() { - local release=$1 generated secret mysql_password + local release=$1 generated secret mysql_password status_password mkdir -p "$SAPOT_ROOT/shared" "$SAPOT_ROOT/shared/certs" "$SAPOT_ROOT/shared/db-data" "$SAPOT_ROOT/shared/gsm-arduino-backups" - secret=$(openssl rand -hex 32); mysql_password=$(openssl rand -hex 32) - for name in server admin gsm-fastapi gsm-arduino; do + secret=$(openssl rand -hex 32); mysql_password=$(openssl rand -hex 32); status_password=$(openssl rand -hex 32) + for name in server admin gsm-fastapi gsm-arduino status; do generated="$SAPOT_ROOT/shared/$name.env" [ -e "$generated" ] && continue - sed -e "s/__GENERATE__/$secret/g" -e "s/__FROM_SERVER_GSM_SECRET__/$secret/g" -e "s/__FROM_SERVER_MYSQL_PASSWORD__/$mysql_password/g" -e "s/mysql+pymysql:\/\/sapot:$secret@db/mysql+pymysql:\/\/sapot:$mysql_password@db/" "$release/config/$name.env.example" > "$generated" + sed -e "s/__GENERATE__/$secret/g" -e "s/__FROM_SERVER_GSM_SECRET__/$secret/g" -e "s/__FROM_SERVER_MYSQL_PASSWORD__/$mysql_password/g" -e "s/__STATUS_DB_PASSWORD__/$status_password/g" -e "s/mysql+pymysql:\/\/sapot:$secret@db/mysql+pymysql:\/\/sapot:$mysql_password@db/" "$release/config/$name.env.example" > "$generated" [ "$name" = server ] && sed -i "s|mysql+pymysql://sapot:$secret@db|mysql+pymysql://sapot:$mysql_password@db|" "$generated" chmod 600 "$generated" done } +prepare_shared_dirs() { + local uid gid + mkdir -p "$SAPOT_ROOT/shared/status" "$SAPOT_ROOT/shared/logs/api" "$SAPOT_ROOT/shared/logs/gsm" + uid=$(docker run --rm --entrypoint id sapot/api:bundle -u 2>/dev/null || true) + gid=$(docker run --rm --entrypoint id sapot/api:bundle -g 2>/dev/null || true) + if [ -n "$uid" ] && [ -n "$gid" ]; then + chown -R "$uid:$gid" "$SAPOT_ROOT/shared/status" "$SAPOT_ROOT/shared/logs/api" 2>/dev/null || log_error "could not chown shared writable directories" + else log_error "could not determine api image uid"; fi +} +provision_status_db_user() { + local release=$1 root_password status_password attempts=24 + root_password=$(grep '^MYSQL_ROOT_PASSWORD=' "$SAPOT_ROOT/shared/server.env" | cut -d= -f2-) + status_password=$(sed -n 's|^STATUS_DATABASE_URL=mysql+pymysql://sapot_status:\([^@]*\)@.*|\1|p' "$SAPOT_ROOT/shared/status.env") + [ -n "$root_password" ] && [ -n "$status_password" ] || { log_error "missing status database credentials"; return 1; } + compose "$release" exec -T -e MYSQL_PWD="$root_password" db mariadb -uroot </dev/null | grep -q 1; then + compose "$release" exec -T -e MYSQL_PWD="$root_password" db mariadb -uroot -e "GRANT SELECT ON sapot.sms_log TO 'sapot_status'@'%'; FLUSH PRIVILEGES;" + return 0 + fi + sleep 5; attempts=$((attempts - 1)) + done + log_error "sms_log did not appear; GSM pending count unavailable until reprovisioned" +} +write_integrity() { + local status=$1 dir="$SAPOT_ROOT/shared/status" tmp + mkdir -p "$dir"; tmp="$dir/.integrity.json.tmp" + printf '{"status": "%s", "verifiedAt": "%s"}\n' "$status" "$(date -u +%Y-%m-%dT%H:%M:%SZ)" > "$tmp" + mv -f "$tmp" "$dir/integrity.json" +} diff --git a/deploy/scripts/lib/retention.sh b/deploy/scripts/lib/retention.sh index 13fc2436..445a7c04 100755 --- a/deploy/scripts/lib/retention.sh +++ b/deploy/scripts/lib/retention.sh @@ -4,6 +4,7 @@ set -euo pipefail root=${SAPOT_ROOT:-/opt/sapot} dry_run=false keep=${SAPOT_RELEASE_RETENTION:-3} +log_days=${SAPOT_LOG_RETENTION_DAYS:-30} [ "${1:-}" = "--dry-run" ] && dry_run=true remove() { if "$dry_run"; then printf 'would remove %s\n' "$1"; else rm -rf -- "$1"; fi; } @@ -25,3 +26,8 @@ done if [ -d "$root/shared/gsm-arduino-backups" ]; then find "$root/shared/gsm-arduino-backups" -type f -printf '%T@ %p\n' | sort -rn | tail -n +$((keep + 1)) | cut -d' ' -f2- | while read -r backup; do remove "$backup"; done fi +if [ -d "$root/shared/logs" ]; then + while IFS= read -r stale; do remove "$stale"; done < <( + find "$root/shared/logs" -type f -mtime "+$log_days" -print + ) +fi diff --git a/deploy/scripts/upgrade.sh b/deploy/scripts/upgrade.sh index b893f709..db1ce453 100755 --- a/deploy/scripts/upgrade.sh +++ b/deploy/scripts/upgrade.sh @@ -5,12 +5,16 @@ SELF=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd); source "$SELF/lib/deploy-com source_release=$(cd "$SELF/.." && pwd); source_manifest="$source_release/manifest.json"; check_schema "$source_manifest"; acquire_lock current=$(readlink -f "$SAPOT_ROOT/releases/current" 2>/dev/null || true); [ -n "$current" ] || { log_error "not installed - use install.sh first"; exit 1; } check_schema "$current/manifest.json" -verify_checksums "$source_release" || { log_error "bundle checksum verification failed"; exit 1; } +if verify_checksums "$source_release"; then integrity_status=PASS; else integrity_status=FAIL; log_error "bundle checksum verification failed"; exit 1; fi current_version=$(manifest_value "$current/manifest.json" version); minimum=$(manifest_value "$source_manifest" minimumUpgradeVersion) [ "$(python3 "$SEMVER" compare "$current_version" "$minimum")" -ge 0 ] || { log_error "current v$current_version is older than minimum upgrade version v$minimum"; exit 1; } disk_preflight "$(manifest_value "$source_manifest" requiredDiskBytes)" version=$(manifest_value "$source_manifest" version); target="$SAPOT_ROOT/releases/v$version"; mkdir -p "$SAPOT_ROOT/releases"; [ -e "$target" ] || cp -a "$source_release" "$target" -for image in "$target"/images/*.tar; do docker load -i "$image"; done; "$VERIFY_DIGESTS" "$target/manifest.json" +prepare_env_files "$target" +write_integrity "$integrity_status" +for image in "$target"/images/*.tar; do docker load -i "$image"; done +prepare_shared_dirs +"$VERIFY_DIGESTS" "$target/manifest.json" compose "$target" up -d db redis; wait_healthy "$target" db; wait_healthy "$target" redis live=$(compose "$current" run --rm api alembic current 2>/dev/null | awk '/^[0-9a-f]+/ {print $1; exit}') head=$(compose "$current" run --rm api alembic heads 2>/dev/null | awk '/^[0-9a-f]+/ {print $1; exit}') @@ -18,5 +22,6 @@ head=$(compose "$current" run --rm api alembic heads 2>/dev/null | awk '/^[0-9a- compose "$target" run --rm api alembic upgrade head compose "$target" up -d; for _ in {1..36}; do curl -kfs https://localhost/version >/dev/null 2>&1 && break; sleep 5; done curl -kfsS https://localhost/version >/dev/null || { log_error "nginx/api did not become ready"; exit 1; } +provision_status_db_user "$target" hardware=$(manifest_value "$SAPOT_ROOT/shared/state.json" gsmHardwarePresent); ln -sfn "$target" "$SAPOT_ROOT/releases/current"; write_state upgrade "$current_version" "$version" "$hardware" "$SELF/lib/retention.sh"; log_pass "upgraded SAPOT from v$current_version to v$version" diff --git a/deploy/tests/pytest.ini b/deploy/tests/pytest.ini new file mode 100644 index 00000000..6126f086 --- /dev/null +++ b/deploy/tests/pytest.ini @@ -0,0 +1,3 @@ +[pytest] +addopts = -ra -q --strict-markers --tb=short +testpaths = . diff --git a/deploy/tests/test_collect_status.py b/deploy/tests/test_collect_status.py new file mode 100644 index 00000000..19be4d17 --- /dev/null +++ b/deploy/tests/test_collect_status.py @@ -0,0 +1,59 @@ +import importlib.util +import json +import pathlib +from datetime import datetime, timezone + +import pytest + +script = pathlib.Path(__file__).resolve().parents[1] / "scripts" / "collect-status.py" +spec = importlib.util.spec_from_file_location("collect_status", script) +collect_status = importlib.util.module_from_spec(spec) +spec.loader.exec_module(collect_status) + + +def check(name, status): return {"check": name, "status": status, "detail": ""} + + +def test_overall_statuses(): + assert collect_status.overall_status([check("api", "PASS")]) == "healthy" + assert collect_status.overall_status([check("api", "PASS"), check("db", "FAIL")]) == "degraded" + assert collect_status.overall_status([check("api", "FAIL")]) == "failed" + assert collect_status.overall_status([]) == "unknown" + + +def test_integrity_is_tolerant_and_does_not_taint_overall(tmp_path): + assert collect_status.read_integrity(str(tmp_path / "missing")) is None + (tmp_path / "bad").write_text("{") + assert collect_status.read_integrity(str(tmp_path / "bad")) is None + data = collect_status.build_payload([check("api", "PASS")], {}, {"status": "FAIL", "verifiedAt": None}, "x", datetime.now(timezone.utc), 0) + assert data["overall"] == "healthy" + + +def test_write_atomic(tmp_path): + collect_status.write_atomic(str(tmp_path), {"overall": "healthy"}) + assert json.loads((tmp_path / "health.json").read_text())["overall"] == "healthy" + assert not (tmp_path / collect_status.TEMP_NAME).exists() + + +def test_closed_port_fails(): + assert collect_status.probe_http("http://127.0.0.1:9", 0.2)[0] is False + + +def test_run_once_degrades_every_unreachable_dependency(tmp_path): + config = collect_status.Config(str(tmp_path), "", "", "mysql+pymysql://x:y@127.0.0.1:9/x", "redis://127.0.0.1:9", .2, 60, {"api": "http://127.0.0.1:9", "admin": "http://127.0.0.1:9"}) + data = collect_status.run_once(config) + assert data["overall"] == "failed" + assert json.loads((tmp_path / "health.json").read_text()) == data + assert data["counters"]["diskFreeBytes"] is not None + + +def test_run_once_writes_unknown_for_unexpected_cycle_error(tmp_path, monkeypatch): + monkeypatch.setattr(collect_status, "collect_checks", lambda _: (_ for _ in ()).throw(RuntimeError("unexpected"))) + config = collect_status.Config(str(tmp_path), "", "", "x", "x", .2, 60, {"api": "http://127.0.0.1:9"}) + assert collect_status.run_once(config)["overall"] == "unknown" + assert "unexpected" in (tmp_path / "health.json").read_text() + + +def test_missing_database_url_fails_fast(monkeypatch): + monkeypatch.delenv("STATUS_DATABASE_URL", raising=False) + with pytest.raises(SystemExit): collect_status.config_from_env() diff --git a/docker-compose.prod.yml b/docker-compose.prod.yml index 88e8725e..788db0da 100644 --- a/docker-compose.prod.yml +++ b/docker-compose.prod.yml @@ -24,6 +24,10 @@ services: image: sapot/api:bundle restart: unless-stopped env_file: [../../../shared/server.env] + environment: + SAPOT_LOG_DIR: /home/app/logs + volumes: + - ../../../shared/logs/api:/home/app/logs depends_on: db: {condition: service_healthy} redis: {condition: service_healthy} @@ -38,7 +42,7 @@ services: image: sapot/nginx:bundle restart: unless-stopped depends_on: - api: {condition: service_healthy} + api: {condition: service_started} tileserver: {condition: service_started} admin: {condition: service_started} ports: ["80:80", "443:443"] @@ -46,6 +50,8 @@ services: - ../config/nginx.prod.conf:/etc/nginx/conf.d/default.conf:ro - ../../../shared/certs:/certs:ro - ../data/static:/usr/share/nginx/static:ro + - ../config/status.html:/usr/share/nginx/status/status.html:ro + - ../../../shared/status:/usr/share/nginx/state:ro admin: image: sapot/admin:bundle restart: unless-stopped @@ -74,6 +80,9 @@ services: environment: HOST: 0.0.0.0 SAPOT_API_URL: https://nginx + GSM_LOG_DIR: /var/log/sapot + volumes: + - ../../../shared/logs/gsm:/var/log/sapot depends_on: db: {condition: service_healthy} expose: ["8001"] @@ -82,3 +91,14 @@ services: interval: 5s timeout: 5s retries: 12 + # This service intentionally has no dependencies and is not depended on. + # It must continue producing a diagnostic snapshot when peers are down. + status-collector: + image: sapot/api:bundle + restart: unless-stopped + env_file: [../../../shared/status.env] + entrypoint: ["python", "/opt/sapot/collect-status.py"] + volumes: + - ../scripts/collect-status.py:/opt/sapot/collect-status.py:ro + - ../../../shared/status:/status + - ../../../shared/certs:/certs:ro diff --git a/docs/deployment/monitoring-logging.md b/docs/deployment/monitoring-logging.md index 53b70f3c..c2c3b5c6 100644 --- a/docs/deployment/monitoring-logging.md +++ b/docs/deployment/monitoring-logging.md @@ -1,73 +1,42 @@ # Monitoring and Logging ---- - ## Mobile app — Sentry -The mobile app integrates Sentry via `@sentry/react-native/expo` (configured in `app.config.ts`): - -- **Sentry project:** `sapot-mobile-app` -- **Organization:** `adriele-matthew-tosino` -- **Sentry URL:** `https://sentry.io/` - -Sentry captures uncaught JS exceptions and native crashes. Release tracking is tied to the EAS build profile and version. - -### Mobile logging scopes - -The app uses a scope-based logger (`features/shared/core/utils/logger.ts`). Control which scopes emit output via: - -```bash -EXPO_PUBLIC_ENABLED_LOG_MODULES=connection,network,sync -``` - -Omitting the variable enables all scopes. Each log entry is also written to a daily rotating log file on-device; retrieve the path via `getLogFilePath()`. - ---- +The mobile app integrates Sentry via `@sentry/react-native/expo`. It captures uncaught JS exceptions and native crashes. Server-side Sentry alerts are not configured. ## Server — application logs -The FastAPI server configures Python's standard `logging` module at startup (`server/app/main.py`). Log output goes to stdout/stderr, captured by systemd journal. - -View live logs: +The FastAPI `app` logger has JSON and text `RotatingFileHandler`s (1 MB plus three backups each), and a `StreamHandler` visible through `docker logs api`. `SAPOT_LOG_DIR` selects the directory; it defaults to `../logs` for local runs and is `/home/app/logs` in Docker. That directory is mounted from `/opt/sapot/shared/logs/api`, as are Gunicorn's access and error logs. ```bash -sudo journalctl -u server-main-api -f +docker compose -p sapot -f /opt/sapot/releases/current/compose/docker-compose.yml logs -f api +tail -f /opt/sapot/shared/logs/api/activity.log ``` -> **TODO (human input required):** Confirm whether JSON structured logging or rotating file logging is enabled, and document the log level configuration. - ---- - -## Server — router metrics collection - -A background thread (`collect_metrics_loop`) polls the MikroTik router for telemetry and writes to the `routerhealth` and `interfacetraffic` MariaDB tables (see [tables.md](../database/tables.md)). The admin frontend reads these tables via the `/admin/router-*` endpoints (see [mikrotik-telemetry.md](../api/mikrotik-telemetry.md)). - -No external monitoring agent is required — data is stored in the existing database. - ---- - -## Server — announcement expiry +## GSM module logs -A second background thread (`expire_announcements_loop`) periodically marks announcements whose `expires_at` has passed by setting `is_expired = True`. This runs entirely in-process; no external scheduler is needed. +The GSM module writes `$GSM_LOG_DIR/sapot.log` through a rotating handler (1 MB plus three backups) and stdout. Docker sets `GSM_LOG_DIR=/var/log/sapot`, mounted from `/opt/sapot/shared/logs/gsm`; an unset value preserves the local working-directory behavior. ---- +`deploy/scripts/lib/retention.sh` removes files under `shared/logs` older than `SAPOT_LOG_RETENTION_DAYS` (30 by default) during install and upgrade. -## GSM module logs +## Health checks — `/status` -The GSM module logs to `GSM-module/GSM-fastapi/sapot.log`. Rotate or clear this file periodically in production. +Open `https:///status` on the LAN. It needs no login and stays available when the API is down because nginx serves a static page and a status snapshot directly. ---- +`status-collector` runs every 60 seconds outside the API process. It probes API, admin, TileServer, and GSM over the compose network, queries Redis and MariaDB directly, and writes `shared/status/health.json` atomically. It uses no Docker socket. Its read-only `sapot_status` database user has SELECT only on `message`, `activity_logs`, and `sms_log`. -## Health checks +| Page item | Meaning | +|---|---| +| Overall | `healthy` means every check passes; `degraded` means API is up but another service is not; `failed` means API is not responding; `unknown` means the collector cycle itself failed. | +| Stale banner | The snapshot is over 180 seconds old. Treat it as a stopped collector, even if the last overall state was healthy. | +| `—` counter | That individual query failed. It does not make the health section fail. | +| Release file integrity | Checksum result recorded during the last install or upgrade. It is provenance, not a live health check. | -No dedicated health-check endpoints are documented. The Nginx proxy (port 443 → Gunicorn :8000) can be used as a liveness check: +The page deliberately excludes IP addresses, user identifiers, internal hostnames, and error messages. For deeper host and bundle checks, run: ```bash -curl -k https://localhost/auth/exists?identifier=probe@example.com +/opt/sapot/releases/current/scripts/doctor.sh +/opt/sapot/releases/current/scripts/doctor.sh --json ``` -A 200 response with `{"exists": true/false}` confirms the stack is reachable. - ---- - -> **TODO (human input required):** Document whether an uptime monitor (e.g. UptimeRobot, Prometheus, or a simple cron ping) is in use, and whether Sentry alerts are configured for the server component. +No cloud uptime monitor is used. This deployment is LAN-first and does not rely on internet access; `/status` and `doctor.sh` are the monitoring surface. diff --git a/scripts/build-bundle.sh b/scripts/build-bundle.sh index 03118ae8..1a9e35da 100755 --- a/scripts/build-bundle.sh +++ b/scripts/build-bundle.sh @@ -61,7 +61,7 @@ cp docker-compose.gsm-hardware.yml "$bundle/compose/" cp deploy/config/* "$bundle/config/" cp docker/gen-certs.sh docker/detect-ip.sh "$bundle/certs/" cp -a deploy/scripts/. "$bundle/scripts/" -chmod +x "$bundle/scripts"/*.sh "$bundle/scripts"/lib/*.sh "$bundle/scripts"/lib/*.py +chmod +x "$bundle/scripts"/*.sh "$bundle/scripts"/*.py "$bundle/scripts"/lib/*.sh "$bundle/scripts"/lib/*.py python3 - "$bundle/manifest.json" "$version" "$git_sha" "$built_at" "$min_version" "$max_version" "$firmware_version" "$fqbn" "$firmware_sha" "$bundle" <<'PY' import json, os, subprocess, sys diff --git a/server/Dockerfile b/server/Dockerfile index 414602de..fc933a26 100644 --- a/server/Dockerfile +++ b/server/Dockerfile @@ -21,7 +21,7 @@ COPY app ./app COPY static ./static COPY alembic.ini ./alembic.ini -RUN mkdir -p logs && chown -R app:app /home/app/server +RUN mkdir -p /home/app/logs && chown -R app:app /home/app/server /home/app/logs USER app EXPOSE 8000 @@ -35,5 +35,5 @@ CMD ["gunicorn", "app.main:app", \ "--worker-connections", "200", \ "--max-requests", "1000", \ "--max-requests-jitter", "100", \ - "--access-logfile", "logs/gunicorn-access.log", \ - "--error-logfile", "logs/gunicorn-error.log"] + "--access-logfile", "/home/app/logs/gunicorn-access.log", \ + "--error-logfile", "/home/app/logs/gunicorn-error.log"] diff --git a/server/app/logging_config.py b/server/app/logging_config.py new file mode 100644 index 00000000..5b8bf1e2 --- /dev/null +++ b/server/app/logging_config.py @@ -0,0 +1,38 @@ +"""Activity-log handler setup for the application logger.""" +import logging +import os +from logging.handlers import RotatingFileHandler + +from pythonjsonlogger import jsonlogger + +_MARKER = "_sapot_activity_configured" +_MAX_BYTES = 10**6 +_BACKUP_COUNT = 3 + + +def configure_activity_logging(logger: logging.Logger, log_dir: str | None = None) -> str: + """Configure file and stdout activity handlers once and return the directory.""" + if getattr(logger, _MARKER, False): + return getattr(logger, "_sapot_activity_dir") + + resolved = os.path.abspath(log_dir or os.environ.get("SAPOT_LOG_DIR") or "../logs") + os.makedirs(resolved, exist_ok=True) + json_handler = RotatingFileHandler( + os.path.join(resolved, "activity.json"), maxBytes=_MAX_BYTES, backupCount=_BACKUP_COUNT + ) + json_handler.setFormatter(jsonlogger.JsonFormatter( + "%(asctime)s %(levelname)s %(user_id)s %(action)s %(entity_id)s %(metadata_json)s %(message)s" + )) + text_handler = RotatingFileHandler( + os.path.join(resolved, "activity.log"), maxBytes=_MAX_BYTES, backupCount=_BACKUP_COUNT + ) + text_handler.setFormatter(logging.Formatter( + "%(asctime)s | %(levelname)s | USER: %(user_id)s | ACTION: %(action)s | %(message)s" + )) + stream_handler = logging.StreamHandler() + stream_handler.setFormatter(logging.Formatter("%(asctime)s | %(levelname)s | %(message)s")) + for handler in (json_handler, text_handler, stream_handler): + logger.addHandler(handler) + setattr(logger, _MARKER, True) + setattr(logger, "_sapot_activity_dir", resolved) + return resolved diff --git a/server/app/main.py b/server/app/main.py index 21e6f3d3..a88c8e89 100644 --- a/server/app/main.py +++ b/server/app/main.py @@ -36,14 +36,13 @@ from app.models.login_attempt import LoginAttempt, RecoveryAttempt # noqa: F401 import logging -from logging.handlers import RotatingFileHandler -from pythonjsonlogger import jsonlogger import time from app.db_operations.auth import SessionDep, engine from app.db_operations.expire_announcements import expire_announcements_loop from app.db_operations.router_metrics_collector import collect_metrics, collect_metrics_loop from app.models.activity import ActivityLog from app.db_operations.token import get_user_id_from_header +from app.logging_config import configure_activity_logging @asynccontextmanager @@ -136,31 +135,10 @@ def get_version(): logger = logging.getLogger("app") logger.setLevel(logging.INFO) -# On Windows: "C:/logs/fastapi_app" -LOG_DIR = os.path.abspath("../logs") - -# Create the directory if it doesn't exist -os.makedirs(LOG_DIR, exist_ok=True) - -# Define full file paths +LOG_DIR = configure_activity_logging(logger) TEXT_LOG_PATH = os.path.join(LOG_DIR, "activity.log") JSON_LOG_PATH = os.path.join(LOG_DIR, "activity.json") -# --- Setup Handlers with the new paths --- -text_handler = RotatingFileHandler(TEXT_LOG_PATH, maxBytes=10**6, backupCount=3) -json_handler = RotatingFileHandler(JSON_LOG_PATH, maxBytes=10**6, backupCount=3) - -# --- JSON Handler (Captures everything) --- -# The format string defines which 'extra' keys to include in the JSON -json_fmt = jsonlogger.JsonFormatter("%(asctime)s %(levelname)s %(user_id)s %(action)s %(entity_id)s %(metadata_json)s %(message)s") -json_handler.setFormatter(json_fmt) -logger.addHandler(json_handler) - -# --- Text Handler (Human Readable) --- -text_fmt = logging.Formatter("%(asctime)s | %(levelname)s | USER: %(user_id)s | ACTION: %(action)s | %(message)s") -text_handler.setFormatter(text_fmt) -logger.addHandler(text_handler) - class UvicornWebSocket403Filter(logging.Filter): """Downgrade uvicorn's own `"WebSocket ... " 403` access line. diff --git a/server/app/tests/test_logging_config.py b/server/app/tests/test_logging_config.py new file mode 100644 index 00000000..1a7e57a6 --- /dev/null +++ b/server/app/tests/test_logging_config.py @@ -0,0 +1,27 @@ +import logging +from logging.handlers import RotatingFileHandler + +from app.logging_config import configure_activity_logging + + +def test_uses_log_dir_env_var(tmp_path, monkeypatch): + monkeypatch.setenv("SAPOT_LOG_DIR", str(tmp_path / "mounted")) + resolved = configure_activity_logging(logging.getLogger("test.activity.env")) + assert resolved == str(tmp_path / "mounted") + assert (tmp_path / "mounted").is_dir() + + +def test_attaches_stream_and_two_rotating_handlers(tmp_path, monkeypatch): + monkeypatch.setenv("SAPOT_LOG_DIR", str(tmp_path)) + logger = logging.getLogger("test.activity.stream") + configure_activity_logging(logger) + assert sum(isinstance(h, RotatingFileHandler) for h in logger.handlers) == 2 + assert any(type(h) is logging.StreamHandler for h in logger.handlers) + + +def test_is_idempotent(tmp_path, monkeypatch): + monkeypatch.setenv("SAPOT_LOG_DIR", str(tmp_path)) + logger = logging.getLogger("test.activity.idempotent") + configure_activity_logging(logger) + configure_activity_logging(logger) + assert len(logger.handlers) == 3 diff --git a/server/app/tests/test_status_contract.py b/server/app/tests/test_status_contract.py new file mode 100644 index 00000000..07cc75d4 --- /dev/null +++ b/server/app/tests/test_status_contract.py @@ -0,0 +1,22 @@ +"""Drift guard for the schema queried by deploy/scripts/collect-status.py.""" +from app.db_operations.connection_manager import _PRESENCE_KEY +from app.models.activity import ActivityLog +from app.models.message import Message + + +def test_presence_key_matches_collector_literal(): + assert _PRESENCE_KEY == "ws:online_users" + + +def test_activity_log_table_and_columns_match_collector_query(): + assert ActivityLog.__tablename__ == "activity_logs" + assert {"created_at", "metadata_json"} <= set(ActivityLog.__table__.columns.keys()) + + +def test_activity_created_at_is_datetime(): + assert ActivityLog.__table__.columns["created_at"].type.python_type.__name__ == "datetime" + + +def test_message_created_at_is_epoch_milliseconds(): + assert Message.__tablename__ == "message" + assert Message.__table__.columns["created_at"].type.python_type is int