From 56561068eabd0c45e40c8eddc8a5c0187c431848 Mon Sep 17 00:00:00 2001
From: houhuan <houhuanya@gmail.com>
Date: Tue, 5 May 2026 11:31:47 +0800
Subject: [PATCH] feat: add HTTP request logging middleware

---
 web/backend/middleware/__init__.py |  0
 web/backend/middleware/logging.py  | 93 ++++++++++++++++++++++++++++++
 2 files changed, 93 insertions(+)
 create mode 100644 web/backend/middleware/__init__.py
 create mode 100644 web/backend/middleware/logging.py

diff --git a/web/backend/middleware/__init__.py b/web/backend/middleware/__init__.py
new file mode 100644
index 0000000..e69de29
diff --git a/web/backend/middleware/logging.py b/web/backend/middleware/logging.py
new file mode 100644
index 0000000..1cba3bb
--- /dev/null
+++ b/web/backend/middleware/logging.py
@@ -0,0 +1,93 @@
+"""HTTP request logging middleware."""
+
+import asyncio
+import logging
+import time
+from starlette.middleware.base import BaseHTTPMiddleware
+from starlette.requests import Request
+from starlette.responses import Response
+
+logger = logging.getLogger(__name__)
+
+# Paths that should not be logged
+_SKIP_PREFIXES = ("/assets", "/ws")
+_SKIP_PATHS = ("/favicon.ico",)
+
+
+class LoggingMiddleware(BaseHTTPMiddleware):
+    """Logs every HTTP request to the database via db_schema.insert_http_log.
+
+    - Skips static assets, WebSocket, and favicon paths.
+    - Measures request duration in milliseconds.
+    - Extracts username from request.state.user when available.
+    - Writes logs asynchronously (non-blocking).
+    - Never lets logging failures break a request.
+    """
+
+    async def dispatch(self, request: Request, call_next) -> Response:
+        path = request.url.path
+
+        # Skip paths that should not be logged
+        if path in _SKIP_PATHS or any(path.startswith(p) for p in _SKIP_PREFIXES):
+            return await call_next(request)
+
+        start = time.perf_counter()
+        status_code = 500  # default if call_next raises
+        try:
+            response = await call_next(request)
+            status_code = response.status_code
+            return response
+        finally:
+            duration_ms = (time.perf_counter() - start) * 1000
+            method = request.method
+            user = getattr(request.state, "user", None)
+            ip = request.client.host if request.client else None
+
+            # Fire-and-forget: never block the response
+            asyncio.create_task(
+                self._write_log(method, path, status_code, duration_ms, user, ip)
+            )
+
+    @staticmethod
+    async def _write_log(
+        method: str,
+        path: str,
+        status_code: int,
+        duration_ms: float,
+        user: str | None,
+        ip: str | None,
+    ) -> None:
+        """Write the log entry in a thread executor to avoid blocking."""
+        try:
+            loop = asyncio.get_event_loop()
+            await loop.run_in_executor(
+                None,
+                lambda: _db_insert(method, path, status_code, duration_ms, user, ip),
+            )
+        except Exception:
+            # Logging must never break the request
+            logger.debug("Failed to write HTTP log", exc_info=True)
+
+
+def _db_insert(
+    method: str,
+    path: str,
+    status_code: int,
+    duration_ms: float,
+    user: str | None,
+    ip: str | None,
+) -> None:
+    """Synchronous DB insert — called inside run_in_executor."""
+    try:
+        from web.backend.services.db_schema import insert_http_log
+
+        insert_http_log(
+            method=method,
+            path=path,
+            status_code=status_code,
+            duration_ms=duration_ms,
+            user=user,
+            ip=ip,
+        )
+    except Exception:
+        logger.debug("DB insert_http_log failed", exc_info=True)