gendesign/backend/app/core/audit_middleware.py
Light1YT 323e399593
All checks were successful
Deploy / changes (push) Successful in 8s
Deploy / build-frontend (push) Has been skipped
Deploy / build-backend (push) Successful in 1m43s
Deploy / build-worker (push) Successful in 2m49s
Deploy / deploy (push) Successful in 1m16s
fix(audit): run_in_threadpool для write_audit_row в async middleware (#1202)
audit_log_middleware зарегистрирован через app.middleware("http") (main.py:92)
→ async dispatch на event loop. После `await call_next(...)` response уже
отдан, но БЛОКИРУЕТ event loop пока идёт sync DB round-trip (SessionLocal/
execute/commit). Это останавливает ВСЕ другие запросы на loop'е до завершения
INSERT'а. При исчерпании connection pool (default 5+10, sync analyze держит
сессию ~15с inline-wait) checkout ждёт pool_timeout=30с НА loop'е → весь API,
включая /health, замирает.

Каждый аудируемый запрос: analyze, КАЖДЫЙ 2с-poll GET /forecast, export,
insight-write. На активной демо-сессии — десятки таких в минуту.

Fix: write_audit_row выполняется через fastapi.concurrency.run_in_threadpool
— sync IO в worker-потоке, event loop свободен для других запросов. Никаких
изменений в самой write_audit_row — она остаётся sync def с собственным
try/except + rollback.

16/16 audit-middleware тестов зелёные (поведение для caller'а не изменилось).

Closes #1202
2026-06-13 05:24:39 +00:00

195 lines
9.1 KiB
Python
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

"""§19 audit log middleware (#962, EPIC18).
Best-effort аудит ключевых/чувствительных действий через FastAPI HTTP-middleware.
Регистрируется в ``app/main.py`` ПОСЛЕ ``rbac_guard`` (Starlette applies middleware
в обратном порядке регистрации, поэтому rbac_guard должен оставаться внешним —
аудитим только запросы, которые RBAC уже пропустил).
Аудируем sensitive actions из ТЗ §19:
* ``POST /api/v1/parcels/{cad}/analyze`` → action='analyze'
* ``GET /api/v1/parcels/{cad}/forecast`` → action='forecast'
* ``GET /api/v1/parcels/{cad}/forecast/export`` → action='export'
* ``POST|PUT|DELETE /api/v1/insights[/{id}]`` → action='insight_write' (#948)
Insight WRITES (POST/PUT/DELETE) — чувствительные ручные записи (§19); их
аудируем. GET-чтения insight'ов НЕ аудируются (read-only, не мутируют).
``/health``, статика, любые non-matched пути НЕ аудируются.
Гарантии:
* Сбой записи в ``audit_log`` НИКОГДА не ломает и не замедляет-фейлит реальный
запрос — write обёрнут в try/except, ошибка логируется, отдаётся настоящий
response.
* Запись делается ПОСЛЕ ``call_next`` (когда response уже готов и status_code
известен) — off the critical latency path.
* В ``settings.testing`` middleware пропускает аудит (как rbac_guard) — юнит-тесты
бьют по app мимо Caddy; аудит-логика покрыта напрямую через
``classify_path`` / ``write_audit_row`` в tests/test_audit_middleware.py.
DB-write использует свежий ``SessionLocal()`` (сессия запроса в middleware
недоступна), commit + close — всё в try/except.
"""
from __future__ import annotations
import logging
import re
from collections.abc import Awaitable, Callable
from fastapi import Request
from fastapi.concurrency import run_in_threadpool
from fastapi.responses import Response
from sqlalchemy import text
from app.core.auth import get_role
from app.core.config import settings
from app.core.db import SessionLocal
logger = logging.getLogger(__name__)
# Кадастровый номер в пути: 66:41:0204016:10 (цифры/двоеточия). Берём «жадный»
# сегмент между /parcels/ и следующим действием — не парсим формат строго,
# чтобы не ломаться на нестандартных кад. номерах.
_CAD = r"(?P<cad>[^/]+)"
# Порядок ВАЖЕН: forecast/export проверяем раньше forecast, иначе export
# заматчится как forecast. Каждый паттерн якорный ($) → точное совпадение пути.
# Эти пути аудируются НЕЗАВИСИМО от HTTP-метода (parcels-действия из §19).
_AUDIT_PATTERNS: tuple[tuple[str, re.Pattern[str]], ...] = (
("export", re.compile(rf"^/api/v1/parcels/{_CAD}/forecast/export$")),
("analyze", re.compile(rf"^/api/v1/parcels/{_CAD}/analyze$")),
("forecast", re.compile(rf"^/api/v1/parcels/{_CAD}/forecast$")),
)
# Insight WRITES (#948, §7.13/§8.9): /api/v1/insights и /api/v1/insights/{id}.
# Аудируем ТОЛЬКО мутации (POST/PUT/DELETE) — GET-чтения insight'ов пропускаем.
_INSIGHT_PATH = re.compile(r"^/api/v1/insights(?:/[^/]+)?$")
_INSIGHT_WRITE_METHODS = frozenset({"POST", "PUT", "DELETE"})
def classify_path(path: str, method: str | None = None) -> tuple[str, str | None] | None:
"""Сопоставить *path* (+ опционально *method*) с аудируемым действием.
Returns ``(action, cad_num)`` если путь — sensitive endpoint, иначе ``None``.
``cad_num`` извлекается из parcels-путей (для insight'ов — ``None``).
*method* нужен только для insight-эндпоинтов (аудируем POST/PUT/DELETE, но
не GET). Parcels-паттерны от метода не зависят. Если *method* не передан
(``None``), insight-ветка пропускается — обратная совместимость со старыми
вызовами ``classify_path(path)``.
"""
for action, pattern in _AUDIT_PATTERNS:
m = pattern.match(path)
if m:
return action, m.group("cad")
if method is not None and method in _INSIGHT_WRITE_METHODS and _INSIGHT_PATH.match(path):
return "insight_write", None
return None
def write_audit_row(
*,
username: str,
action: str,
method: str,
path: str,
status_code: int,
cad_num: str | None,
) -> None:
"""Best-effort вставка одной строки в ``audit_log``.
Открывает свежий ``SessionLocal()``, commit, close — всё в try/except.
Любая ошибка логируется и ГЛОТАЕТСЯ (re-raise здесь сломал бы основной
запрос) — это намеренное исключение из «no silent except»: аудит вторичен
по отношению к запросу пользователя.
"""
role: str | None
try:
role = get_role(username)
except KeyError:
# Юзер прошёл сюда через rbac_guard, так что обычно известен; но
# на гонке reload roles.yaml / прямом вызове — пишем role=None, не падаем.
role = None
db = SessionLocal()
try:
db.execute(
text(
"INSERT INTO audit_log "
"(username, role, action, method, path, cad_num, status_code) "
"VALUES (:username, :role, :action, :method, :path, :cad_num, "
":status_code)"
),
{
"username": username,
"role": role,
"action": action,
"method": method,
"path": path,
"cad_num": cad_num,
"status_code": status_code,
},
)
db.commit()
except Exception:
# Best-effort: НЕ re-raise — аудит не должен ломать запрос.
logger.exception(
"audit_log write failed (user=%s action=%s path=%s) — request unaffected",
username,
action,
path,
)
try:
db.rollback()
except Exception:
logger.exception("audit_log rollback failed")
finally:
db.close()
async def audit_log_middleware(
request: Request,
call_next: Callable[[Request], Awaitable[Response]],
) -> Response:
"""Аудируем sensitive actions ПОСЛЕ выполнения запроса (best-effort)."""
# Test-mode bypass (как rbac_guard). Аудит-логика покрыта напрямую в
# tests/test_audit_middleware.py через classify_path / write_audit_row.
if settings.testing:
return await call_next(request)
matched = classify_path(request.url.path, request.method)
# Выполняем сам запрос ВСЕГДА (даже non-matched) — сначала получаем response.
response = await call_next(request)
if matched is None:
return response
action, cad_num = matched
username = request.headers.get("X-Authenticated-User")
if not username:
# Без auth-header (локальный curl мимо Caddy) rbac_guard уже отдал бы 401,
# но если мы тут — нечего атрибутировать, аудит пропускаем.
return response
# Write после готового response — off the critical path для САМОГО клиента
# (response уже отдан выше), но БЛОКИРУЕТ event loop пока идёт sync DB
# round-trip (SessionLocal/execute/commit). Это останавливает ВСЕ другие
# запросы на loop'е до завершения insert'аа при исчерпании connection
# pool checkout ждёт `pool_timeout=30s` НА loop'е, замораживая весь API
# включая /health (#1202). Выполняем write в threadpool через
# `run_in_threadpool` — sync IO в worker-потоке, event loop свободен.
try:
await run_in_threadpool(
write_audit_row,
username=username,
action=action,
method=request.method,
path=request.url.path,
status_code=response.status_code,
cad_num=cad_num,
)
except Exception:
logger.exception("audit middleware unexpected error — request unaffected")
return response