diff --git a/src/backend/api/middleware/logging.py b/src/backend/api/middleware/logging.py index 8f349cf..d696666 100644 --- a/src/backend/api/middleware/logging.py +++ b/src/backend/api/middleware/logging.py @@ -6,9 +6,14 @@ from fastapi import Request, Response from starlette.middleware.base import BaseHTTPMiddleware from sqlalchemy import insert +from src.backend.api.middleware.rate_limit import RateLimitMiddleware from src.backend.database import async_session_factory from src.backend.models.orm.access_log import AccessLog +# AccessLog.action is String(100): a long path (with query-string-like +# segments) silently failed the insert before this truncation existed. +_ACTION_MAX_LENGTH = 100 + class AccessLogMiddleware(BaseHTTPMiddleware): """Middleware that logs every API request to the access_logs table.""" @@ -30,11 +35,12 @@ class AccessLogMiddleware(BaseHTTPMiddleware): # Log asynchronously (don't block response) try: + action = f"{request.method} {request.url.path}"[:_ACTION_MAX_LENGTH] async with async_session_factory() as session: await session.execute( insert(AccessLog).values( user_id=user_id, - action=f"{request.method} {request.url.path}", + action=action, details={ "method": request.method, "path": request.url.path, @@ -42,7 +48,7 @@ class AccessLogMiddleware(BaseHTTPMiddleware): "status_code": response.status_code, "duration_ms": round(duration_ms, 2), }, - ip_address=request.client.host if request.client else None, + ip_address=RateLimitMiddleware._client_ip(request), user_agent=request.headers.get("user-agent", "")[:500], ) ) diff --git a/src/backend/tests/test_access_log_middleware.py b/src/backend/tests/test_access_log_middleware.py new file mode 100644 index 0000000..9b45a74 --- /dev/null +++ b/src/backend/tests/test_access_log_middleware.py @@ -0,0 +1,118 @@ +"""Unit tests for AccessLogMiddleware (gitea#36 point 6). + +- action must be truncated to fit AccessLog.action (String(100)): an + untruncated long path used to fail the INSERT silently (swallowed by the + broad except in dispatch()). +- ip_address must come from the same `_client_ip` the rate limiter uses + (proxy-aware), not the raw `request.client.host`, which behind + Nginx/Flask is always localhost. + +These stub out async_session_factory and inspect the compiled INSERT +statement directly, rather than going through a real DB round trip: Core +`insert()` against the test's in-memory SQLite has an unrelated +autoincrement quirk (unrelated to this fix) that makes end-to-end +assertions on the persisted row unreliable here. +""" +from unittest.mock import patch + +from starlette.requests import Request +from starlette.responses import Response + +from src.backend.api.middleware.logging import AccessLogMiddleware + + +class _FakeSession: + """Records the statement passed to execute(); no real DB involved.""" + + def __init__(self): + self.executed_stmt = None + + async def execute(self, stmt): + self.executed_stmt = stmt + + async def commit(self): + pass + + async def __aenter__(self): + return self + + async def __aexit__(self, *exc): + return False + + +def _make_request(path: str, extra_headers: list[tuple[bytes, bytes]] | None = None) -> Request: + scope = { + "type": "http", + "method": "GET", + "path": path, + "query_string": b"", + "headers": extra_headers or [], + "client": ("127.0.0.1", 12345), + } + return Request(scope) + + +async def test_long_path_action_is_truncated(): + fake_session = _FakeSession() + long_path = "/api/files/" + "a" * 200 + + with patch( + "src.backend.api.middleware.logging.async_session_factory", + return_value=fake_session, + ): + middleware = AccessLogMiddleware(app=None) + request = _make_request(long_path) + + async def call_next(_req): + return Response(status_code=404) + + await middleware.dispatch(request, call_next) + + assert fake_session.executed_stmt is not None + params = fake_session.executed_stmt.compile().params + assert len(params["action"]) <= 100 + assert params["action"] == f"GET {long_path}"[:100] + + +async def test_short_path_action_is_unaffected(): + fake_session = _FakeSession() + + with patch( + "src.backend.api.middleware.logging.async_session_factory", + return_value=fake_session, + ): + middleware = AccessLogMiddleware(app=None) + request = _make_request("/api/settings/") + + async def call_next(_req): + return Response(status_code=200) + + await middleware.dispatch(request, call_next) + + params = fake_session.executed_stmt.compile().params + assert params["action"] == "GET /api/settings/" + + +async def test_ip_address_uses_client_ip_resolution(): + """trusted_proxy_count defaults to 1: the last XFF hop (our own proxy's + add) is trusted, not request.client.host (always the proxy itself).""" + fake_session = _FakeSession() + + with patch( + "src.backend.api.middleware.logging.async_session_factory", + return_value=fake_session, + ): + middleware = AccessLogMiddleware(app=None) + request = _make_request( + "/api/settings/", + extra_headers=[(b"x-forwarded-for", b"203.0.113.7, 10.0.0.1")], + ) + + async def call_next(_req): + return Response(status_code=200) + + await middleware.dispatch(request, call_next) + + params = fake_session.executed_stmt.compile().params + assert params["ip_address"] == "10.0.0.1" + assert params["ip_address"] != "127.0.0.1" # not request.client.host