Files
gw/backend/app/middleware/logging.py
T
ponzischeme89 6d44e05de4 v1
2026-04-18 07:23:55 +12:00

294 lines
12 KiB
Python

"""
Request logging middleware.
Prints a clean, colour-coded line for every meaningful HTTP request.
Context-aware: pulls the email, member status, service type, etc. from the
request body for the most important endpoints so you can read the log without
needing to replay the request.
Format
------
METHOD /path/to/endpoint STATUS timing origin
↳ human-readable context (when relevant)
Localhost / loopback addresses are rendered as local:PORT rather than the
raw IP.
"""
from __future__ import annotations
import io
import json
import sys
import time
from typing import Optional
from rich.console import Console
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
# Force UTF-8 on Windows so arrow / symbol characters render correctly in any
# terminal (Windows Terminal, VS Code, PowerShell). On other platforms the
# default encoding is already UTF-8.
def _make_console() -> Console:
if sys.platform == "win32" and hasattr(sys.stdout, "buffer"):
out = io.TextIOWrapper(sys.stdout.buffer, encoding="utf-8", line_buffering=True)
return Console(highlight=False, markup=True, file=out)
return Console(highlight=False, markup=True)
_console = _make_console()
# ── Paths that are too noisy to log ───────────────────────────────────────────
_SKIP = frozenset({"/health", "/favicon.ico", "/robots.txt"})
_BODY_METHODS = frozenset({"POST", "PUT", "PATCH"})
# ── Colour maps ───────────────────────────────────────────────────────────────
_METHOD_STYLE: dict[str, str] = {
"GET": "bold #6ea8fe", # soft blue
"POST": "bold #75b798", # soft green
"PUT": "bold #e6a817", # amber
"PATCH": "bold #c586c0", # lavender
"DELETE": "bold #f28b82", # soft red
"HEAD": "dim",
"OPTIONS": "dim",
}
def _status_style(code: int) -> str:
if code < 300:
return "bold green"
if code < 400:
return "bold cyan"
if code < 500:
return "bold yellow"
return "bold red"
def _timing_style(ms: float) -> str:
if ms < 200:
return "white"
if ms < 1_000:
return "yellow"
return "bold red"
# ── Helpers ───────────────────────────────────────────────────────────────────
_LOCAL_HOSTS = {"127.0.0.1", "::1", "0.0.0.0", "localhost", "::ffff:127.0.0.1"}
def _origin(request: Request) -> str:
host = request.client.host if request.client else "unknown"
port = request.url.port or 8000
if host in _LOCAL_HOSTS:
return f"[dim]local:{port}[/dim]"
return f"[dim]{host}[/dim]"
def _body(raw: bytes) -> Optional[dict]:
if not raw:
return None
try:
obj = json.loads(raw)
return obj if isinstance(obj, dict) else None
except (json.JSONDecodeError, ValueError):
return None
def _shorten(path: str, width: int = 58) -> str:
"""Left-pad the path to *width* chars, truncating with ellipsis if needed."""
if len(path) > width:
path = path[: width - 1] + ""
return f"{path:<{width}}"
# ── Context extraction ────────────────────────────────────────────────────────
# Each branch returns a *markup* string (may contain [colour] tags) or None.
def _context(path: str, method: str, data: Optional[dict], status: int) -> Optional[str]: # noqa: C901
d = data or {}
em = d.get("email", "")
# ── Admin auth ────────────────────────────────────────────────────────────
if path.endswith("/auth/login") and "/members/" not in path:
if status < 400:
return f"[dim]admin[/dim] · {em}"
return f"[red]✗[/red] bad credentials · {em}"
# ── Member auth ───────────────────────────────────────────────────────────
if "/members/auth/login/verify" in path:
if status < 400:
return f"[dim]member 2FA[/dim] · {em} · [green]verified ✓[/green]"
return f"[red]✗[/red] bad 2FA code · {em}"
if "/members/auth/login" in path and path.endswith("/login"):
if status < 400:
return f"[dim]member login[/dim] · {em}"
return f"[red]✗[/red] bad password · {em}"
if "/members/auth/refresh" in path:
return None # token rotation — no useful body detail
# ── Claim flow ────────────────────────────────────────────────────────────
if "/members/claim/request" in path:
return f"[dim]claim request[/dim] · {em}"
if "/members/claim/complete" in path:
if status < 400:
return f"[green]account claimed[/green] · {em}"
return f"[red]✗[/red] claim failed · {em}"
# ── Member: profile ───────────────────────────────────────────────────────
if method == "PUT" and path.endswith("/members/me"):
fields = [k for k in d]
if fields:
return "[dim]updated[/dim] · " + ", ".join(fields)
return None
# ── Member: onboarding ────────────────────────────────────────────────────
if "/members/onboarding/contract" in path:
signer = d.get("signer_name", "")
if status < 400:
return f"[green]contract signed[/green] · {signer}"
return None
if method == "PUT" and "/members/onboarding" in path:
if d.get("complete_onboarding"):
return "[dim]onboarding complete[/dim] → [yellow]pending_contract[/yellow]"
return None
# ── Member: bookings ──────────────────────────────────────────────────────
if method == "POST" and path.endswith("/members/bookings"):
svc = d.get("service_type", "")
notes = d.get("notes", "")
label = _service_label(svc)
parts = [label] + ([notes[:50]] if notes else [])
return "[dim]booking request[/dim] · " + " · ".join(p for p in parts if p)
# ── Admin: create member ──────────────────────────────────────────────────
if (
method == "POST"
and "/admin/members" in path
and not any(seg in path for seg in ("/activate", "/walks", "/bookings", "/messages"))
):
first = d.get("first_name", "")
last = d.get("last_name", "")
em2 = d.get("email", "")
name = f"{first} {last}".strip()
parts = [n for n in (name, em2) if n]
return "[dim]new member[/dim] · " + " · ".join(parts)
if method == "POST" and "/admin/members/" in path and path.endswith("/activate"):
return "status → [green]active ✓[/green]"
if method == "PUT" and "/admin/members/" in path:
s = d.get("member_status")
if s:
return f"status → [cyan]{s}[/cyan]"
return None
# ── Admin: walks ──────────────────────────────────────────────────────────
if method == "POST" and "/admin/walks" in path:
svc = _service_label(d.get("service_type", ""))
dur = d.get("duration_minutes", "")
parts = [svc] + ([f"{dur} min"] if dur else [])
return "[dim]walk recorded[/dim] · " + " · ".join(p for p in parts if p)
# ── Admin: messages ───────────────────────────────────────────────────────
if method == "POST" and "/admin/messages" in path:
subject = d.get("subject", "")
return f"[dim]message sent[/dim] · {subject}" if subject else "[dim]message sent[/dim]"
# ── Admin: bookings ───────────────────────────────────────────────────────
if method == "PUT" and "/admin/bookings/" in path:
s = d.get("status")
if s:
_colour = {"confirmed": "green", "cancelled": "red", "completed": "cyan"}.get(s, "yellow")
return f"status → [{_colour}]{s}[/{_colour}]"
if d.get("admin_notes"):
return "[dim]admin notes updated[/dim]"
return None
# ── Admin: notifications ──────────────────────────────────────────────────
if method == "POST" and "/admin/notifications/run" in path:
return "[dim]notification run triggered[/dim]"
if method == "PUT" and "/admin/notifications/settings" in path:
keys = list(d.keys())
return "[dim]settings updated[/dim] · " + ", ".join(keys) if keys else None
# ── Contact leads ─────────────────────────────────────────────────────────
if "/contact" in path and method == "POST":
name = d.get("full_name") or d.get("name", "")
pet = d.get("pet_name", "")
email_fallback = d.get("email", "")
parts = [name or email_fallback] + ([f"dog: {pet}"] if pet else [])
return "[dim]lead[/dim] · " + " · ".join(p for p in parts if p)
# ── Generic 4xx hints ─────────────────────────────────────────────────────
if status == 401:
return "[red]✗[/red] unauthorized"
if status == 403:
return "[red]✗[/red] forbidden"
if status == 422:
return "[yellow]⚠[/yellow] validation error"
if status == 429:
return "[yellow]⚠[/yellow] rate limited"
return None
def _service_label(svc: str) -> str:
return {"pack_walk": "Pack Walk", "1_1_walk": "1-1 Walk", "puppy_visit": "Puppy Visit"}.get(svc, svc)
# ── Middleware ────────────────────────────────────────────────────────────────
class RequestLogMiddleware(BaseHTTPMiddleware):
"""
Logs every non-trivial HTTP request to the console via Rich.
Body reads are cached by Starlette's Request.body() so downstream
handlers always see the full body unchanged.
"""
async def dispatch(self, request: Request, call_next):
path = request.url.path
method = request.method
if path in _SKIP or method == "OPTIONS":
return await call_next(request)
# Read and cache body before handing to the route handler.
raw = b""
if method in _BODY_METHODS:
raw = await request.body() # Starlette caches in request._body
data = _body(raw)
t0 = time.perf_counter()
response = await call_next(request)
elapsed = (time.perf_counter() - t0) * 1_000
status = response.status_code
ctx = _context(path, method, data, status)
origin = _origin(request)
method_w = f"{method:<7}"
timing = f"{elapsed:>7.1f}ms"
path_w = _shorten(path)
method_styled = f"[{_METHOD_STYLE.get(method, 'white')}]{method_w}[/]"
status_styled = f"[{_status_style(status)}]{status}[/]"
timing_styled = f"[{_timing_style(elapsed)}]{timing}[/]"
_console.print(
f" {method_styled} {path_w} {status_styled} {timing_styled} {origin}"
)
if ctx:
_console.print(f" [dim]↳[/dim] {ctx}")
return response