fix(logging): action troncata a 100, ip_address dal client IP proxy-aware (#36 punto 6)
action era action=f"{method} {path}" senza limite: un path lungo falliva
l'INSERT (String(100)), inghiottito dal try/except generico, e la riga di
audit spariva in silenzio. Troncata a 100 caratteri. ip_address usava
request.client.host, che dietro Nginx/Flask e' sempre il proxy: ora usa
RateLimitMiddleware._client_ip(request), lo stesso risolutore proxy-aware
del rate limiter (X-Forwarded-For con trusted_proxy_count).
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
@@ -6,9 +6,14 @@ from fastapi import Request, Response
|
|||||||
from starlette.middleware.base import BaseHTTPMiddleware
|
from starlette.middleware.base import BaseHTTPMiddleware
|
||||||
from sqlalchemy import insert
|
from sqlalchemy import insert
|
||||||
|
|
||||||
|
from src.backend.api.middleware.rate_limit import RateLimitMiddleware
|
||||||
from src.backend.database import async_session_factory
|
from src.backend.database import async_session_factory
|
||||||
from src.backend.models.orm.access_log import AccessLog
|
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):
|
class AccessLogMiddleware(BaseHTTPMiddleware):
|
||||||
"""Middleware that logs every API request to the access_logs table."""
|
"""Middleware that logs every API request to the access_logs table."""
|
||||||
@@ -30,11 +35,12 @@ class AccessLogMiddleware(BaseHTTPMiddleware):
|
|||||||
|
|
||||||
# Log asynchronously (don't block response)
|
# Log asynchronously (don't block response)
|
||||||
try:
|
try:
|
||||||
|
action = f"{request.method} {request.url.path}"[:_ACTION_MAX_LENGTH]
|
||||||
async with async_session_factory() as session:
|
async with async_session_factory() as session:
|
||||||
await session.execute(
|
await session.execute(
|
||||||
insert(AccessLog).values(
|
insert(AccessLog).values(
|
||||||
user_id=user_id,
|
user_id=user_id,
|
||||||
action=f"{request.method} {request.url.path}",
|
action=action,
|
||||||
details={
|
details={
|
||||||
"method": request.method,
|
"method": request.method,
|
||||||
"path": request.url.path,
|
"path": request.url.path,
|
||||||
@@ -42,7 +48,7 @@ class AccessLogMiddleware(BaseHTTPMiddleware):
|
|||||||
"status_code": response.status_code,
|
"status_code": response.status_code,
|
||||||
"duration_ms": round(duration_ms, 2),
|
"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],
|
user_agent=request.headers.get("user-agent", "")[:500],
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
|
|||||||
@@ -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
|
||||||
Reference in New Issue
Block a user