api: log HTTPException responses (5xx + 4xx) to the journal

Failures surfaced via HTTPException (e.g. wizard dest-provisioning errors
raised as HTTPException(500, "dest provisioning failed: …")) were turned
into responses by FastAPI and never logged — only the access line showed,
so the real DB error went to the browser and vanished from the journal.

Register a StarletteHTTPException handler that logs 5xx at ERROR (with
exc_info, capturing the chained cause) and 4xx at WARNING, then defers to
the default handler. Also configure pipekit's logger to emit to stderr so
INFO-level records aren't dropped by uvicorn's last-resort handler.
Unhandled (non-HTTPException) errors were already logged by uvicorn.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
Paul Trowbridge 2026-06-17 09:32:47 -04:00
parent 7202b86210
commit 356e5f7799

View File

@ -7,14 +7,36 @@ content-negotiation complexity and keeps the API curl-testable.
from __future__ import annotations from __future__ import annotations
import logging
import sys
from contextlib import asynccontextmanager from contextlib import asynccontextmanager
from fastapi import FastAPI from fastapi import FastAPI, Request
from fastapi.exception_handlers import http_exception_handler
from starlette.exceptions import HTTPException as StarletteHTTPException
from .. import __version__, db, jrunner from .. import __version__, db, jrunner
from ..web import mount_web from ..web import mount_web
from .routes import connections, introspect, modules, runs, system from .routes import connections, introspect, modules, runs, system
_log = logging.getLogger("pipekit.web")
def _configure_logging() -> None:
"""Route pipekit's loggers to stderr (→ journal) with a consistent format.
Uvicorn configures only its own loggers, not the root, so without this our
records would fall through to the last-resort handler (WARNING+ only) and
INFO breadcrumbs would vanish. Idempotent safe to call per create_app."""
base = logging.getLogger("pipekit")
if not base.handlers:
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(logging.Formatter(
"%(asctime)s %(levelname)s [%(name)s] %(message)s"))
base.addHandler(handler)
base.setLevel(logging.INFO)
base.propagate = False
@asynccontextmanager @asynccontextmanager
async def _lifespan(app: FastAPI): async def _lifespan(app: FastAPI):
@ -24,7 +46,24 @@ async def _lifespan(app: FastAPI):
def create_app() -> FastAPI: def create_app() -> FastAPI:
_configure_logging()
app = FastAPI(title="Pipekit", version=__version__, lifespan=_lifespan) app = FastAPI(title="Pipekit", version=__version__, lifespan=_lifespan)
@app.exception_handler(StarletteHTTPException)
async def _logged_http_exception_handler(request: Request,
exc: StarletteHTTPException):
# FastAPI turns HTTPException into a normal response and never logs it,
# so failures surfaced this way (e.g. wizard dest-provisioning errors)
# were invisible in the journal. Log them, then defer to the default
# handler for the actual response.
if exc.status_code >= 500:
_log.error("%s %s -> %d: %s", request.method, request.url.path,
exc.status_code, exc.detail, exc_info=exc)
elif exc.status_code >= 400:
_log.warning("%s %s -> %d: %s", request.method, request.url.path,
exc.status_code, exc.detail)
return await http_exception_handler(request, exc)
app.include_router(system.router) app.include_router(system.router)
app.include_router(connections.router, prefix="/api") app.include_router(connections.router, prefix="/api")
app.include_router(introspect.router, prefix="/api") app.include_router(introspect.router, prefix="/api")