Week 5 — AlertDesk Observability and Benchmarks

alertdesk/alertdesk/app.py

@@ -9,9 +9,12 @@
 from pydantic import BaseModel, Field
 
 from . import db
+from .observability import RequestLoggingMiddleware, configure_logging
 from .auth import require
 from .spec import can_transition
 
+configure_logging()
+
 
 @asynccontextmanager
 async def lifespan(_app: FastAPI):
@@ -28,6 +31,8 @@ async def lifespan(_app: FastAPI):
     lifespan=lifespan,
 )
 
+app.add_middleware(RequestLoggingMiddleware)
+
 
 class TicketCreate(BaseModel):
     title: str = Field(min_length=1)

alertdesk/alertdesk/observability.py

@@ -0,0 +1,58 @@
+"""Structured request logging that excludes credentials and request bodies."""
+
+from __future__ import annotations
+
+import json
+import logging
+import time
+from typing import Any
+
+from starlette.middleware.base import BaseHTTPMiddleware, RequestResponseEndpoint
+from starlette.requests import Request
+from starlette.responses import Response
+
+
+class JsonFormatter(logging.Formatter):
+    def format(self, record: logging.LogRecord) -> str:
+        fields: dict[str, Any] = {
+            "timestamp": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
+            "level": record.levelname.lower(),
+            "logger": record.name,
+            "message": record.getMessage(),
+        }
+        fields.update(getattr(record, "event_fields", {}))
+        return json.dumps(fields, separators=(",", ":"), default=str)
+
+
+def configure_logging() -> None:
+    logger = logging.getLogger("alertdesk.http")
+    if not any(getattr(handler, "_alertdesk_json", False) for handler in logger.handlers):
+        handler = logging.StreamHandler()
+        handler.setFormatter(JsonFormatter())
+        handler._alertdesk_json = True  # type: ignore[attr-defined]
+        logger.addHandler(handler)
+    logger.setLevel(logging.INFO)
+    logger.propagate = False
+
+
+class RequestLoggingMiddleware(BaseHTTPMiddleware):
+    async def dispatch(
+        self, request: Request, call_next: RequestResponseEndpoint
+    ) -> Response:
+        started = time.perf_counter()
+        status_code = 500
+        try:
+            response = await call_next(request)
+            status_code = response.status_code
+            return response
+        finally:
+            elapsed_ms = round((time.perf_counter() - started) * 1000, 3)
+            logging.getLogger("alertdesk.http").info(
+                "http_request",
+                extra={"event_fields": {
+                    "method": request.method,
+                    "path": request.url.path,
+                    "status_code": status_code,
+                    "duration_ms": elapsed_ms,
+                }},
+            )

alertdesk/docs/BENCHMARKS.md

@@ -0,0 +1,113 @@
+# Week 5 performance baseline and observability
+
+## Benchmark
+
+`scripts/benchmark.py` measures end-to-end HTTP latency for ticket creation and
+listing against a running AlertDesk instance. It performs five warm-up pairs by
+default, then records 100 measured create/list pairs. Results report mean,
+median, p95, minimum, and maximum latency in milliseconds as JSON. The script
+uses Python's standard library and the analyst bearer token configured by the
+sample client spec.
+
+Start the service in one terminal with `python -m alertdesk.cli`, then run
+`python scripts/benchmark.py` in another. Options include `--base-url`, `--token`,
+`--iterations`, and `--warmup`. Benchmark records use unique synthetic titles
+and are persisted by the target service; use a disposable database for repeatable
+runs. Listing time naturally rises as the table grows because the endpoint returns
+all tickets. Results depend on machine load, database size, and whether the API
+is local, so compare runs only under similar conditions.
+
+## Baseline
+
+No latency target is specified in the client brief. The following local
+development run is a recorded baseline; it is not a production service-level
+objective.
+
+#### October 28, 2026 run
+
+- Date: 2026-10-28
+- Command: `python scripts/benchmark.py --base-url http://127.0.0.1:8765 --token analyst-token --iterations 100 --warmup 5`
+- Database: disposable SQLite database; 40,960 bytes after the run (105 tickets
+  and 105 audit events, including five warm-up pairs)
+- Measured iterations: 100 create/list pairs (plus five warm-up pairs)
+- Emitted summary:
+
+```json
+{
+  "base_url": "http://127.0.0.1:8765",
+  "iterations": 100,
+  "warmup": 5,
+  "units": "ms",
+  "create_ticket": {
+    "count": 100,
+    "mean_ms": 28.758,
+    "median_ms": 29.668,
+    "p95_ms": 40.342,
+    "min_ms": 14.379,
+    "max_ms": 53.993
+  },
+  "list_tickets": {
+    "count": 100,
+    "mean_ms": 22.908,
+    "median_ms": 25.399,
+    "p95_ms": 35.28,
+    "min_ms": 10.062,
+    "max_ms": 37.285
+  }
+}
+```
+
+The API was started locally on port 8765 with `ALERTDESK_DB` pointed at the
+disposable database. The tracked development database was left unchanged.
+
+#### November 3, 2026 run
+
+- Date: 2026-11-03
+- Command: `python scripts/benchmark.py --base-url http://127.0.0.1:8765 --token analyst-token --iterations 100 --warmup 5`
+- Database: disposable SQLite database; 40,960 bytes after the run (105 tickets and 105 audit events, including five warm-up pairs).
+- Measured iterations: 100 create/list pairs (plus five warm-up pairs).
+- Emitted summary:
+
+```json
+{
+  "base_url": "http://127.0.0.1:8765",
+  "iterations": 100,
+  "warmup": 5,
+  "units": "ms",
+  "create_ticket": {
+    "count": 100,
+    "mean_ms": 20.029,
+    "median_ms": 19.222,
+    "p95_ms": 36.804,
+    "min_ms": 9.771,
+    "max_ms": 38.485
+  },
+  "list_tickets": {
+    "count": 100,
+    "mean_ms": 15.642,
+    "median_ms": 11.91,
+    "p95_ms": 30.017,
+    "min_ms": 6.566,
+    "max_ms": 38.602
+  }
+}
+```
+
+## Request logging
+
+The API emits one JSON log event per HTTP request with timestamp, method, URL
+path, status code, and elapsed milliseconds. The logger intentionally excludes
+headers, bearer tokens, query strings, request bodies, and ticket data. These
+fields are enough to identify slow routes and error rates without copying alert
+contents into general application logs. Logs go to stderr through Python's
+standard logging handler and can be collected by the process supervisor or
+container runtime.
+
+## Operational notes
+
+- The benchmark includes HTTP client, API, SQLite, and response serialization time.
+- The list endpoint has no pagination, so its latency and response size grow with
+  the number of stored tickets.
+- The benchmark creates records and does not clean them up; point it at a
+  disposable database when measuring repeatedly.
+- This is a local development baseline, not a capacity or concurrency test.

alertdesk/scripts/benchmark.py

@@ -0,0 +1,92 @@
+"""Measure AlertDesk create and list request latency against a running API.
+
+Example: python scripts/benchmark.py --base-url http://127.0.0.1:8000 --iterations 100
+The service must already be running. Each run creates uniquely named tickets.
+"""
+
+from __future__ import annotations
+
+import argparse
+import json
+import math
+import statistics
+import time
+import urllib.error
+import urllib.request
+import uuid
+
+
+def request(base_url: str, path: str, token: str, payload: dict | None = None) -> tuple[int, float]:
+    data = json.dumps(payload).encode() if payload is not None else None
+    req = urllib.request.Request(
+        f"{base_url.rstrip('/')}{path}", data=data,
+        headers={"Authorization": f"Bearer {token}", "Content-Type": "application/json"},
+        method="POST" if data is not None else "GET",
+    )
+    started = time.perf_counter()
+    try:
+        with urllib.request.urlopen(req, timeout=30) as response:
+            response.read()
+            status = response.status
+    except urllib.error.HTTPError as exc:
+        exc.read()
+        status = exc.code
+    elapsed_ms = (time.perf_counter() - started) * 1000
+    if not 200 <= status < 300:
+        raise RuntimeError(f"{req.method} {path} returned HTTP {status}")
+    return status, elapsed_ms
+
+
+def percentile(values: list[float], percentile_value: float) -> float:
+    ordered = sorted(values)
+    index = max(0, math.ceil(percentile_value * len(ordered)) - 1)
+    return ordered[index]
+
+
+def summarize(values: list[float]) -> dict[str, float]:
+    return {
+        "count": len(values),
+        "mean_ms": round(statistics.mean(values), 3),
+        "median_ms": round(statistics.median(values), 3),
+        "p95_ms": round(percentile(values, 0.95), 3),
+        "min_ms": round(min(values), 3),
+        "max_ms": round(max(values), 3),
+    }
+
+
+def main() -> None:
+    parser = argparse.ArgumentParser(description=__doc__)
+    parser.add_argument("--base-url", default="http://127.0.0.1:8000")
+    parser.add_argument("--token", default="analyst-token")
+    parser.add_argument("--iterations", type=int, default=100)
+    parser.add_argument("--warmup", type=int, default=5)
+    args = parser.parse_args()
+    if args.iterations < 1 or args.warmup < 0:
+        parser.error("--iterations must be positive and --warmup cannot be negative")
+
+    create_times: list[float] = []
+    list_times: list[float] = []
+    for index in range(args.warmup + args.iterations):
+        payload = {
+            "title": f"benchmark-{uuid.uuid4().hex}",
+            "description": "Synthetic benchmark record",
+            "severity": "low",
+        }
+        _, create_ms = request(args.base_url, "/tickets", args.token, payload)
+        _, list_ms = request(args.base_url, "/tickets", args.token)
+        if index >= args.warmup:
+            create_times.append(create_ms)
+            list_times.append(list_ms)
+
+    print(json.dumps({
+        "base_url": args.base_url.rstrip("/"),
+        "iterations": args.iterations,
+        "warmup": args.warmup,
+        "units": "ms",
+        "create_ticket": summarize(create_times),
+        "list_tickets": summarize(list_times),
+    }, indent=2))
+
+
+if __name__ == "__main__":
+    main()