Logging cleanup, better colors, suppress more useless messages. Enable reloading in devmode again (needs uvicorn.run to function).

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:

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)

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

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