dashboards/scripts/watch-store-perf.py

#!/usr/bin/env python3
"""Phase 14 task 04: watch the running dev server for `database is locked`.

Sampled, not exhaustive: every ~20 s a signed-in pass hits the paths a page actually loads
(``/api/health``, ``/api/summary``, ``/api/metrics``, a 3-host x 9-metric 90-day
``/api/system/history``) and records the wall time beside the store's own evidence — the
``store-error`` rows in the ``event`` table, the WAL file size, the database size.

Run it in the background while the dev server keeps polling the fleet:

    set -a; . ./.env.dev; set +a
    setsid nohup uv run python scripts/watch-store-perf.py > /tmp/watch.out 2>&1 < /dev/null &

Writes ``data/logs/store-perf-watch.log`` (human), ``store-perf-watch.tsv`` (machine) and
``store-perf-watch.json`` (the summary every path ran against). ``data/`` is gitignored, so those
are local evidence for ``data/logs/NOTES-store-perf.md``, never tracked artifacts.
"""

from __future__ import annotations

import json
import os
import sqlite3
import statistics
import sys
import time
from pathlib import Path

import httpx

#: Repo root, so the paths below mean the same tree wherever the watch is invoked from
#: (the same anchor ``scripts/store_perf_probe.py`` uses).
ROOT = Path(__file__).resolve().parents[1]

BASE_URL = os.environ.get("DASH_WATCH_URL", "http://127.0.0.1:8090")
ADMIN_PASSWORD = os.environ.get("DASH_ADMIN_PASSWORD", "")
DB_PATH = Path(os.environ.get("DASH_WATCH_DB", ROOT / "data" / "dashboards.sqlite3"))
OUT = Path(os.environ.get("DASH_WATCH_OUT", ROOT / "data" / "logs"))
DURATION_SECONDS = float(os.environ.get("DASH_WATCH_SECONDS", "1500"))
INTERVAL_SECONDS = float(os.environ.get("DASH_WATCH_INTERVAL", "20"))

#: What a page load may cost. Everything here is a panel the operator is looking at.
PAGE_BUDGET_MS = 250.0

METRICS = [
    "cpu.usage_pct", "cpu.temp_c", "cpu.load1", "mem.used_pct", "disk.used_pct@/",
    "disk.used_pct@/home", "net.rx_bps", "net.tx_bps", "gpu.busy_pct@0",
]


def store_evidence(db: sqlite3.Connection, since: float) -> dict[str, float | int | str]:
    """The store's own record, read on a separate connection while the server runs."""
    total = db.execute("SELECT COUNT(*) FROM event WHERE kind='store-error'").fetchone()[0]
    recent = db.execute(
        "SELECT COUNT(*) FROM event WHERE kind='store-error' AND ts>=?", (since,)
    ).fetchone()[0]
    last = db.execute(
        "SELECT message FROM event WHERE kind='store-error' ORDER BY ts DESC LIMIT 1"
    ).fetchone()
    return {
        "store_errors_total": total,
        "store_errors_in_window": recent,
        "last_store_error": (last[0] if last else ""),
    }


def timed(client: httpx.Client, path: str) -> tuple[float, int]:
    started = time.perf_counter()
    try:
        response = client.get(path)
        code = response.status_code
    except httpx.HTTPError:  # a refused request is a sample too
        return (time.perf_counter() - started) * 1000.0, -1
    return (time.perf_counter() - started) * 1000.0, code


def main() -> int:
    started = time.perf_counter()
    OUT.mkdir(parents=True, exist_ok=True)
    log_path = OUT / "store-perf-watch.log"
    tsv_path = OUT / "store-perf-watch.tsv"
    json_path = OUT / "store-perf-watch.json"
    samples: list[dict[str, float | int | str]] = []

    client = httpx.Client(base_url=BASE_URL, timeout=60.0, follow_redirects=False)
    login = client.post("/api/auth/login", json={"username": "admin", "password": ADMIN_PASSWORD})
    if login.status_code != 200:
        print(f"login failed: {login.status_code} {login.text[:200]}", flush=True)
        return 1
    client.headers["X-CSRF-Token"] = login.json()["csrf"]

    hosts = [t["name"] for t in client.get("/api/config").json()["system"]["targets"]]
    host_query = "".join(f"hosts={h}&" for h in hosts) or "hosts=driveripper&"
    metrics_query = "".join(f"metrics={m}&" for m in METRICS)
    paths = {
        "health": "/api/health",
        "summary": "/api/summary",
        "metrics": "/api/metrics?source=host",
        "history_90d": f"/api/system/history?{host_query}{metrics_query}range=90d",
    }

    db = sqlite3.connect(f"file:{DB_PATH}?mode=ro", uri=True, timeout=30.0)
    started_wall = time.time()
    with log_path.open("a", buffering=1) as log:
        log.write(f"# watch start {time.strftime('%Y-%m-%dT%H:%M:%S')} "
                  f"budget={PAGE_BUDGET_MS:.0f} ms interval={INTERVAL_SECONDS:.0f} s "
                  f"duration={DURATION_SECONDS:.0f} s hosts={hosts}\n")
        while time.perf_counter() - started < DURATION_SECONDS:
            row: dict[str, float | int | str] = {
                "t": round(time.time(), 1),
                "elapsed_s": round(time.perf_counter() - started, 1),
            }
            for name, path in paths.items():
                ms, code = timed(client, path)
                row[f"{name}_ms"] = round(ms, 1)
                row[f"{name}_code"] = code
            wal = DB_PATH.with_name(DB_PATH.name + "-wal")
            row["wal_mb"] = round((wal.stat().st_size if wal.exists() else 0) / 1e6, 2)
            row["db_mb"] = round(DB_PATH.stat().st_size / 1e6, 1)
            try:
                row.update(store_evidence(db, started_wall))
            except sqlite3.Error as exc:
                row["store_errors_total"] = -1
                row["store_errors_in_window"] = -1
                row["last_store_error"] = f"read failed: {exc}"
            samples.append(row)
            worst = max(float(row[f"{n}_ms"]) for n in paths)
            log.write(
                f"{row['t']} elapsed={row['elapsed_s']:7.1f}s "
                + " ".join(f"{n}={row[f'{n}_ms']:7.1f}ms" for n in paths)
                + f" worst={worst:7.1f}ms wal={row['wal_mb']}MB db={row['db_mb']}MB"
                + f" store-error(total={row['store_errors_total']},"
                  f" in-window={row['store_errors_in_window']})\n"
            )
            time.sleep(INTERVAL_SECONDS)

    # ---- summary
    def stat(name: str, fn) -> float:
        values = [float(s[f"{name}_ms"]) for s in samples]
        return round(fn(values), 1)

    summary: dict[str, object] = {
        "started": time.strftime("%Y-%m-%dT%H:%M:%S", time.localtime(started_wall)),
        "duration_seconds": round(time.perf_counter() - started, 1),
        "passes": len(samples),
        "db": str(DB_PATH),
        "db_mb_first": samples[0]["db_mb"],
        "db_mb_last": samples[-1]["db_mb"],
        "wal_mb_first": samples[0]["wal_mb"],
        "wal_mb_max": max(float(s["wal_mb"]) for s in samples),
        "wal_mb_last": samples[-1]["wal_mb"],
        "store_errors_total": samples[-1]["store_errors_total"],
        "store_errors_in_window": samples[-1]["store_errors_in_window"],
        "last_store_error": samples[-1]["last_store_error"],
        "paths": {
            name: {
                "median_ms": stat(name, statistics.median),
                "p95_ms": stat(name, lambda v: sorted(v)[max(0, int(len(v) * 0.95) - 1)]),
                "max_ms": stat(name, max),
            }
            for name in paths
        },
        "budget_ms": PAGE_BUDGET_MS,
        "passes_over_budget": sum(
            1 for s in samples if max(float(s[f"{n}_ms"]) for n in paths) > PAGE_BUDGET_MS
        ),
        "non_200_responses": sum(
            1 for s in samples for n in paths if int(s[f"{n}_code"]) not in (200, 404)
        ),
    }
    json_path.write_text(json.dumps({"summary": summary, "samples": samples}, indent=2) + "\n")
    with log_path.open("a", buffering=1) as log:
        log.write("# summary\n")
        for name, values in summary["paths"].items():  # type: ignore[index]
            log.write(f"#   {name:12s} median={values['median_ms']:8.1f} ms "
                      f"p95={values['p95_ms']:8.1f} ms max={values['max_ms']:8.1f} ms\n")
        log.write(f"#   store-error rows in window: {summary['store_errors_in_window']} "
                  f"(total {summary['store_errors_total']})\n")
        log.write(f"#   WAL first/max/last MB: {summary['wal_mb_first']} / "
                  f"{summary['wal_mb_max']} / {summary['wal_mb_last']}\n")
        log.write(f"#   passes over the {PAGE_BUDGET_MS:.0f} ms budget: "
                  f"{summary['passes_over_budget']} of {summary['passes']}\n")

    header = ["t"] + [f"{n}_ms" for n in paths] + ["wal_mb", "db_mb", "store_errors_in_window"]
    with tsv_path.open("w") as tsv:
        tsv.write("\t".join(header) + "\n")
        for sample in samples:
            tsv.write("\t".join(str(sample.get(key, "")) for key in header) + "\n")
    print(json.dumps(summary, indent=2))
    return 0


if __name__ == "__main__":
    sys.exit(main())