[Fable 5][P2] audit_log_middleware: синхронная запись в БД внутри async-middleware блокирует event loop на каждом sensitive-запросе #1202

New issue

Closed

opened 2026-06-13 04:49:42 +00:00 by bot-backend · 0 comments

bot-backend commented

2026-06-13 04:49:42 +00:00

Collaborator

Из армейского ревью Claude Fable 5 (2026-06-11)

Confirmed by 2/2 адверсариальных верификатора, severity P2 (concurrency), confidence 0.75.

Файл

backend/app/core/audit_middleware.py:177

Evidence (цитата кода)

    # Write после готового response — off the critical path. Любой сбой внутри
    # write_audit_row проглатывается там же; здесь дополнительная страховка.
    try:
        write_audit_row(
            username=username,
            action=action,
            method=request.method,
            path=request.url.path,

Why bug

write_audit_row делает блокирующий SessionLocal()/execute/commit прямо в async dispatch — каждый audited-запрос (analyze, КАЖДЫЙ 2-секундный poll GET /forecast, export, insight-write) стопорит весь event loop на время DB round-trip и задерживает отдачу самого ответа (вопреки «off the critical path»). При исчерпании пула (engine default 5+10; sync analyze держит connection во время внешних HTTP-вызовов до ~25с и 15с inline-wait) checkout ждёт pool_timeout 30с НА LOOP'е — весь API, включая /health, замирает. Заодно каждый pending-poll форсайта пишет строку аудита (bloat audit_log).

Suggested fix

Выполнять write_audit_row через anyio.to_thread.run_sync / run_in_threadpool (или fire-and-forget BackgroundTask после отправки ответа); опционально не аудировать 202-ответы поллинга forecast.

Verify notes

[real/P2] GET /forecast поллится каждые 2с (parcels.py:1252); middleware зарегистрирован app.middleware("http") (main.py:92) — async dispatch на event loop. Строка 177 зовёт sync write_audit_row: SessionLocal() (sync engine db.py:8, pool 5+10, pool_timeout 30с) + execute(INSERT) + commit — блокирующие round-trip'ы на loop'е, без to_thread. Uvicorn без --workers → один loop; при исчерпании пула (sync analyze держит сессию 15с) checkout ждёт до 30с на loop'е — стоит весь API, включая /health.
[real/P2] write_audit_row вызывается напрямую в async dispatch (main.py:92) без to_thread/run_in_threadpool/BackgroundTask; внутри sync SessionLocal/execute/commit (db.py: sync engine, pool 5+10, timeout 30s). Конвенция проекта обратная: аудируемые хендлеры — sync def, insights.py:19 прямо пишет «async def + sync db.execute… заблокировало бы loop». Каждый 4s-poll GET /forecast блокирует loop; при исчерпании пула (analyze держит сессию ~15с inline-wait) checkout до 30с на loop'е — весь API.

Provenance

Finders: api-core, sweep-async
Confidence: 0.75
Originally batched at: main@d796027

## Из армейского ревью Claude Fable 5 (2026-06-11) Confirmed by 2/2 адверсариальных верификатора, severity **P2** (concurrency), confidence 0.75. ## Файл [`backend/app/core/audit_middleware.py:177`](backend/app/core/audit_middleware.py:177) ## Evidence (цитата кода) ``` # Write после готового response — off the critical path. Любой сбой внутри # write_audit_row проглатывается там же; здесь дополнительная страховка. try: write_audit_row( username=username, action=action, method=request.method, path=request.url.path, ``` ## Why bug write_audit_row делает блокирующий SessionLocal()/execute/commit прямо в async dispatch — каждый audited-запрос (analyze, КАЖДЫЙ 2-секундный poll GET /forecast, export, insight-write) стопорит весь event loop на время DB round-trip и задерживает отдачу самого ответа (вопреки «off the critical path»). При исчерпании пула (engine default 5+10; sync analyze держит connection во время внешних HTTP-вызовов до ~25с и 15с inline-wait) checkout ждёт pool_timeout 30с НА LOOP'е — весь API, включая /health, замирает. Заодно каждый pending-poll форсайта пишет строку аудита (bloat audit_log). ## Suggested fix Выполнять write_audit_row через anyio.to_thread.run_sync / run_in_threadpool (или fire-and-forget BackgroundTask после отправки ответа); опционально не аудировать 202-ответы поллинга forecast. ## Verify notes - [real/P2] GET /forecast поллится каждые 2с (parcels.py:1252); middleware зарегистрирован app.middleware("http") (main.py:92) — async dispatch на event loop. Строка 177 зовёт sync write_audit_row: SessionLocal() (sync engine db.py:8, pool 5+10, pool_timeout 30с) + execute(INSERT) + commit — блокирующие round-trip'ы на loop'е, без to_thread. Uvicorn без --workers → один loop; при исчерпании пула (sync analyze держит сессию 15с) checkout ждёт до 30с на loop'е — стоит весь API, включая /health. - [real/P2] write_audit_row вызывается напрямую в async dispatch (main.py:92) без to_thread/run_in_threadpool/BackgroundTask; внутри sync SessionLocal/execute/commit (db.py: sync engine, pool 5+10, timeout 30s). Конвенция проекта обратная: аудируемые хендлеры — sync def, insights.py:19 прямо пишет «async def + sync db.execute… заблокировало бы loop». Каждый 4s-poll GET /forecast блокирует loop; при исчерпании пула (analyze держит сессию ~15с inline-wait) checkout до 30с на loop'е — весь API. ## Provenance - Finders: `api-core, sweep-async` - Confidence: 0.75 - Originally batched at: main@d796027