#!/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())