diff --git a/paskia/fastapi/__main__.py b/paskia/fastapi/__main__.py index 50d2182..63b867d 100644 --- a/paskia/fastapi/__main__.py +++ b/paskia/fastapi/__main__.py @@ -7,12 +7,12 @@ from urllib.parse import urlparse from fastapi_vue.hostutil import parse_endpoint from uvicorn import Config, Server +from uvicorn import run as uvicorn_run from paskia import globals as _globals from paskia.bootstrap import bootstrap_if_needed from paskia.config import PaskiaConfig from paskia.db.background import flush -from paskia.fastapi import app as fastapi_app from paskia.fastapi import reset as reset_cmd from paskia.util import startupbox from paskia.util.hostutil import normalize_origin @@ -188,7 +188,7 @@ def main(): devmode = bool(os.environ.get("FASTAPI_VUE_FRONTEND_URL")) run_kwargs: dict = { - "log_level": "info", + "log_level": "warning", # Suppress startup messages; we use custom logging "access_log": False, # We use custom AccessLogMiddleware instead } @@ -199,8 +199,6 @@ def main(): raise SystemExit(f"Dev mode requires localhost:4402, got {host}:{port}") run_kwargs["reload"] = True run_kwargs["reload_dirs"] = ["paskia"] - # Suppress uvicorn startup messages in dev mode - run_kwargs["log_level"] = "warning" async def async_main(): await _globals.init( @@ -220,10 +218,18 @@ def main(): async with asyncio.TaskGroup() as tg: for ep in endpoints: tg.create_task( - Server(Config(app=fastapi_app, **run_kwargs, **ep)).serve() + Server( + Config(app="paskia.fastapi:app", **run_kwargs, **ep) + ).serve() ) + elif devmode: + # Use uvicorn.run for proper reload support (it handles subprocess spawning) + ep = endpoints[0] + uvicorn_run("paskia.fastapi:app", **run_kwargs, **ep) else: - server = Server(Config(app=fastapi_app, **run_kwargs, **endpoints[0])) + server = Server( + Config(app="paskia.fastapi:app", **run_kwargs, **endpoints[0]) + ) await server.serve() try: diff --git a/paskia/fastapi/logging.py b/paskia/fastapi/logging.py index 5fa4281..82f4ccd 100644 --- a/paskia/fastapi/logging.py +++ b/paskia/fastapi/logging.py @@ -13,18 +13,18 @@ logger = logging.getLogger("paskia.access") _RESET = "\033[0m" _STATUS_INFO = "\033[32m" # 1xx (green) -_STATUS_OK = "\033[92m" # 2xx (bright green) +_STATUS_OK = "\033[1;92m" # 2xx (bright green) _STATUS_REDIRECT = "\033[32m" # 3xx (green) _STATUS_CLIENT_ERR = "\033[0;31m" # 4xx (red) -_STATUS_SERVER_ERR = "\033[1;31m" # 5xx (bright red) +_STATUS_SERVER_ERR = "\033[1;91m" # 5xx (bold bright red) _METHOD_READ = "\033[0;34m" # GET, HEAD, OPTIONS (blue) -_METHOD_WRITE = "\033[1;34m" # POST, PUT, DELETE, PATCH (bright blue) -_HOST = "\033[1;30m" # hostname (dark grey) -_PATH = "\033[0m" # path (default) -_TIMING = "\033[2m" # timing (dim) -_WS_OPEN = "\033[1;33m" # WebSocket connect (bright yellow) -_WS_CLOSE = "\033[0;33m" # WebSocket disconnect (yellow) -_WS_STATUS = "\033[1;30m" # WebSocket close status (dark grey) +_METHOD_WRITE = "\033[1;94m" # POST, PUT, DELETE, PATCH (bold bright blue) +_HOST = "\033[38;5;242m" # hostname (dark grey) +_PATH = "\033[38;5;248m" # path (default) +_TIMING = "\033[38;5;242m" # timing/devmode (dark grey) +_WS_OPEN = "\033[1;93m" # WebSocket connect (bold bright yellow) +_WS_CLOSE = "\033[33m" # WebSocket disconnect (yellow) +_WS_STATUS = "\033[38;5;242m" # WebSocket close status (dark grey) def format_ipv6_network(ip: str) -> str: @@ -116,25 +116,39 @@ def _next_ws_id() -> int: return ws_id -def log_ws_open(client: str, host: str, path: str) -> int: +def log_ws_open(ws) -> int: """Log WebSocket connection open. Returns connection ID for use in close.""" use_color = sys.stderr.isatty() ws_id = _next_ws_id() + client = ws.client.host if ws.client else "-" + host = ws.headers.get("host", "-") + path = ws.url.path + origin = ws.headers.get("origin") + ip = format_client_ip(client).ljust(15) id_str = f"{ws_id:02d}".ljust(7) # Align with method field (7 chars) + # Determine if origin should be shown (omit when same as host) + # Origin header includes scheme (e.g., "https://example.com"), compare host part + origin_host = origin.split("://", 1)[-1] if origin else None + show_origin = origin_host and origin_host != host + if use_color: # 🔌 aligned with status (takes ~2 char width), ID aligned with method prefix = f"🔌 {_WS_OPEN}{id_str}{_RESET}" host_str = f"{_HOST}{host}{_RESET}" path_str = f"{_PATH}{path}{_RESET}" + origin_str = ( + f" {_RESET}from {_HOST}{origin_host}{_RESET}" if show_origin else "" + ) else: prefix = f"WS+ {id_str}" host_str = host path_str = path + origin_str = f" from {origin_host}" if show_origin else "" - logger.info(f"{ip} {prefix} {host_str}{path_str}") + logger.info(f"{ip} {prefix} {host_str}{path_str}{origin_str}") return ws_id @@ -158,15 +172,12 @@ WS_CLOSE_CODES = { } -def log_ws_close( - client: str, ws_id: int, close_code: int | None, duration_ms: float -) -> None: +def log_ws_close(ws_id: int, close_code: int | None, duration: float) -> None: """Log WebSocket connection close with duration and status.""" use_color = sys.stderr.isatty() - ip = format_client_ip(client).ljust(15) id_str = f"{ws_id:02d}".ljust(7) # Align with method field (7 chars) - timing = f"{duration_ms:.0f}ms" + timing = f"{duration * 1000:.0f}ms" # Convert close code to status text if close_code is None: @@ -184,7 +195,7 @@ def log_ws_close( status_str = status timing_str = timing - logger.info(f"{ip} {prefix} {status_str} {timing_str}") + logger.info(f"{' ' * 15} {prefix} {status_str} {timing_str}") class AccessLogMiddleware(BaseHTTPMiddleware): @@ -216,3 +227,5 @@ def configure_access_logging(): logger.addHandler(handler) logger.setLevel(logging.INFO) logger.propagate = False + # Suppress watchfiles "X changes detected" INFO messages (keep WARNING for reload notification) + logging.getLogger("watchfiles.main").setLevel(logging.WARNING) diff --git a/paskia/fastapi/mainapp.py b/paskia/fastapi/mainapp.py index f1e6335..6abb6c5 100644 --- a/paskia/fastapi/mainapp.py +++ b/paskia/fastapi/mainapp.py @@ -20,6 +20,8 @@ from paskia.util import hostutil, passphrase, vitedev configure_access_logging() configure_db_logging() +_access_logger = logging.getLogger("paskia.access") + # Vue Frontend static files frontend = Frontend( Path(__file__).parent.parent / "frontend-build", @@ -59,7 +61,6 @@ async def lifespan(app: FastAPI): # pragma: no cover - startup path if frontend.devmode: logging.getLogger("uvicorn").setLevel(logging.INFO) logging.getLogger("uvicorn.error").setLevel(logging.WARNING) - await frontend.load() await start_background() yield diff --git a/paskia/fastapi/wsutil.py b/paskia/fastapi/wsutil.py index 0a64d4f..158f867 100644 --- a/paskia/fastapi/wsutil.py +++ b/paskia/fastapi/wsutil.py @@ -21,12 +21,8 @@ def websocket_error_handler(func): @wraps(func) async def wrapper(ws: WebSocket, *args, **kwargs): - client = ws.client.host if ws.client else "-" - host = ws.headers.get("host", "-") - path = ws.url.path - start = time.perf_counter() - ws_id = log_ws_open(client, host, path) + ws_id = log_ws_open(ws) close_code = None try: @@ -47,8 +43,7 @@ def websocket_error_handler(func): logging.exception("Internal Server Error") await ws.send_json({"status": 500, "detail": "Internal Server Error"}) finally: - duration_ms = (time.perf_counter() - start) * 1000 - log_ws_close(client, ws_id, close_code, duration_ms) + log_ws_close(ws_id, close_code, time.perf_counter() - start) return wrapper