94 lines
2.9 KiB
Python
94 lines
2.9 KiB
Python
"""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)
|