From 90e328df66fa4631a898f0c7d4c795763c14c8ef Mon Sep 17 00:00:00 2001 From: bot-backend Date: Thu, 6 Aug 2026 14:27:26 +0000 Subject: [PATCH] =?UTF-8?q?fix(tradein/auth):=20=D0=BE=D1=82=D0=BA=D0=B0?= =?UTF-8?q?=D0=B7=20=D0=BF=D0=BE=20=D0=BD=D0=B0=D1=81=D1=8B=D1=89=D0=B5?= =?UTF-8?q?=D0=BD=D0=B8=D1=8E=20=E2=80=94=20=D0=B4=D0=BE=20=D0=B2=D1=8B?= =?UTF-8?q?=D0=B1=D0=BE=D1=80=D0=BA=D0=B8=20=D0=B8=D0=B7=20=D0=91=D0=94=20?= =?UTF-8?q?=D0=B8=20=D1=81=20=D0=B0=D0=B3=D1=80=D0=B5=D0=B3=D0=B8=D1=80?= =?UTF-8?q?=D0=BE=D0=B2=D0=B0=D0=BD=D0=BD=D1=8B=D0=BC=20=D1=81=D0=BB=D0=B5?= =?UTF-8?q?=D0=B4=D0=BE=D0=BC=20(#2715)=20(#2734)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- tradein-mvp/backend/app/api/v1/audit.py | 17 +- tradein-mvp/backend/app/api/v1/auth.py | 147 ++++++++++++++-- tradein-mvp/backend/app/core/password.py | 33 +++- tradein-mvp/backend/tests/test_audit_api.py | 33 ++++ tradein-mvp/backend/tests/test_auth_api.py | 182 ++++++++++++++++++++ 5 files changed, 394 insertions(+), 18 deletions(-) diff --git a/tradein-mvp/backend/app/api/v1/audit.py b/tradein-mvp/backend/app/api/v1/audit.py index e592d5b1..feac11aa 100644 --- a/tradein-mvp/backend/app/api/v1/audit.py +++ b/tradein-mvp/backend/app/api/v1/audit.py @@ -58,6 +58,12 @@ async def list_accounts( count(*) FILTER (WHERE event_type = 'api_request') AS request_count, count(*) FILTER (WHERE event_type = 'estimate_request') AS search_count FROM user_events + -- Событие без имени — не аккаунт (#2715: `login_verify_saturated` + -- пишется с пустым именем намеренно — отказ случается ДО того, как + -- на имя посмотрели). Без фильтра строка встала бы ПЕРВОЙ (её + -- last_seen_at — момент атаки), а её кнопка в UI раскрывалась бы в + -- /audit/accounts/{username} с `min_length=1`, то есть в ошибку. + WHERE username <> '' GROUP BY username ORDER BY last_seen_at DESC """ @@ -182,12 +188,16 @@ async def analytics_dashboard( db.execute( text( """ + -- NULLIF(username, ''): безымянные события (#2715) — СОБЫТИЯ, они + -- честно входят в total_events, но не люди: count(DISTINCT) их + -- игнорирует по NULL, иначе первая же атака навсегда добавила бы + -- фантомного пользователя в счётчик уникальных. SELECT count(*) AS total_events, - count(DISTINCT username) AS distinct_users, + count(DISTINCT NULLIF(username, '')) AS distinct_users, count(*) FILTER ( WHERE created_at >= now() - INTERVAL '24 hours' ) AS events_last_24h, - count(DISTINCT username) FILTER ( + count(DISTINCT NULLIF(username, '')) FILTER ( WHERE created_at >= now() - INTERVAL '24 hours' ) AS active_users_last_24h FROM user_events @@ -204,7 +214,7 @@ async def analytics_dashboard( """ SELECT date_trunc('day', created_at)::date AS day, count(*) AS events, - count(DISTINCT username) AS users + count(DISTINCT NULLIF(username, '')) AS users -- см. выше (#2715) FROM user_events WHERE created_at >= now() - make_interval(days => CAST(:days AS int)) GROUP BY date_trunc('day', created_at)::date @@ -261,6 +271,7 @@ async def analytics_dashboard( count(*) FILTER (WHERE event_type = 'estimate_request') AS searches, max(created_at) AS last_seen FROM user_events + WHERE username <> '' -- не аккаунт, см. /audit/accounts выше (#2715) GROUP BY username ORDER BY events DESC LIMIT 50 diff --git a/tradein-mvp/backend/app/api/v1/auth.py b/tradein-mvp/backend/app/api/v1/auth.py index bfe43cf6..af346cde 100644 --- a/tradein-mvp/backend/app/api/v1/auth.py +++ b/tradein-mvp/backend/app/api/v1/auth.py @@ -40,6 +40,10 @@ Security: флуда получал 429 столько раз, сколько пытался. Ключ — IP, поэтому защита поднимает стоимость атаки, но не закрывает её (подделка за вторым прокси, общий адрес за NAT, ротация через ботнет) — см. docstring той же функции. + Отказ по насыщению выдаётся ДО выборки из реестра (#2715): иначе на этом + пути оставалась бы единственная работа, время которой зависит от того, + существует ли имя, — а bcrypt, который эту разницу ровняет, до него уже не + доходит. След инцидента — агрегированный, `_saturated_429`. - Поверх него — ГЛОБАЛЬНЫЙ счётчик неудач на ИМЯ, без IP в ключе (#2571): лимит по паре (username, IP) распределённый перебор обходит целиком, просто меняя адрес. Превышение порога не блокирует вход, а замедляет ответ @@ -54,6 +58,7 @@ from __future__ import annotations import asyncio import logging import secrets +import time from typing import Annotated from fastapi import APIRouter, Depends, HTTPException, Request, Response @@ -61,7 +66,12 @@ from pydantic import BaseModel, Field from sqlalchemy.orm import Session from app.core.config import settings -from app.core.password import PasswordVerifyOverloadedError, hash_password, verify_password_bounded +from app.core.password import ( + PasswordVerifyOverloadedError, + hash_password, + verify_password_bounded, + verify_slots_saturated, +) from app.core.ratelimit import SlidingWindowLimiter, _client_ip from app.services.auth_session import create_session, get_user_by_username, revoke_session from app.services.identity_store import AccessState, get_identity_db @@ -174,6 +184,115 @@ def _throttle_delay_s(fails_in_window: int) -> float: return min(settings.login_username_throttle_max_delay_s, 2.0 ** min(excess - 1, 16)) +# Не чаще одной записи в это окно на ВСЕ отказы по насыщению (#2715). Окно, а не +# запись на запрос, потому что лог у бэкенда общий и ограниченный (docker +# json-file, max-size 20m × max-file 3): при флуде в сотни запросов в секунду +# строка на каждый отказ прокручивает 60 МБ за минуты и выселяет ВСЕ остальные +# логи ровно во время атаки — то есть в момент, когда они нужнее всего. +# Значение не в настройках намеренно: это не тюнинг, а «человек читает лог», и +# крутить его нечем — меньше секунды возвращает исходную проблему, больше +# ухудшает разрешение по времени, не давая взамен ничего. +_SATURATION_REPORT_WINDOW_S = 1.0 + +# Отказов с прошлой записи и когда была прошлая запись (monotonic; None — записи +# ещё не было). Обычные глобалы без лока — по той же причине, что и счётчик +# слотов в `app.core.password`: обе строчки исполняются в потоке событийного +# цикла и между чтением и записью нет `await`. +_saturation_rejected = 0 +_saturation_reported_at: float | None = None + + +def _saturated_429(ip: str) -> HTTPException: + """429 «слоты сверки заняты» + АГРЕГИРОВАННЫЙ след инцидента. + + Событие неудачного входа тут не пишется и бюджет неудач по имени не + тратится сознательно (#2712): пароль не проверялся, это не попытка входа, а + трата бюджета означала бы, что насыщением можно заблокировать чужую учётку. + Но тогда весь инцидент виден ровно здесь, и до #2715 — только строкой в + логе на каждый отклонённый запрос (см. `_SATURATION_REPORT_WINDOW_S`). + + Поэтому на окно приходится одна строка в лог И одно событие + `login_verify_saturated` в `user_events` — с числом отказов, накопленных с + прошлой записи. Событие важнее строки: аудит переживает и ротацию логов, и + редеплой. Первый отказ отчитывается сразу, а не в конце окна: одиночная + аномалия обязана быть видна, даже если продолжения не будет. + + `since_prev_s` в payload — НЕ дубль `created_at`, а единственный способ + прочитать счётчик правильно. Хвост копится, пока не придёт следующий отказ: + атака кончилась в 03:00, 900 отказов остались неотчитанными — и во вторник + одиночный 429 соседа по NAT унёс бы их все в запись, датированную вторником + и подписанную АДРЕСОМ СОСЕДА. С `since_prev_s` видно, что 901 отказ + накоплен за неделю, а не за секунду, и что читать `ip` в этой записи не + надо. `None` — первая запись за жизнь процесса, сравнивать не с чем. + + Уровень ERROR, а не WARNING, — не косметика: бэкенд поднят с + `LoggingIntegration(level=INFO, event_level=ERROR)` (app/main.py), то есть + ровно с ERROR запись становится событием GlitchTip, а WARNING остаётся + строкой в docker-логе, которая умирает с ротацией и редеплоем. Цена + прецедента известна (#2674): монитор писал WARNING про протухшие куки — и + событий было ноль. Спама не будет: запись не чаще раза в окно, и все они + группируются в один issue (шаблон сообщения один). + + Чего это НЕ делает: у GlitchTip-проекта нет ни правил, ни получателей + (#2673), так что уведомление никому не уйдёт — событие будет видно в + интерфейсе, но не в чьём-то телефоне. Проверить доставку поведенчески + сейчас не на чем, и утверждать её здесь было бы враньём. + + `username=""` — не заглушка: имя не пишем ПОТОМУ, что отказ случился до + того, как мы на него посмотрели. Записывай мы присланное, атакующий + наполнял бы аудит строками с любым именем на выбор. Пустое имя — не аккаунт, + и списки аудита его отфильтровывают (`WHERE username <> ''` в + `app/api/v1/audit.py`), иначе оно встало бы первой строкой в списке + аккаунтов и фантомом в `count(DISTINCT username)`. `ip` — адрес последнего + отклонённого запроса, то есть ОБРАЗЕЦ: при распределённом флуде адресов + много, и по одной записи их не восстановить (счётчик — восстановит). + + Потолок объёма: час непрерывной атаки — это 3600 строк в `user_events` + (в таблице за всю её жизнь ~3.4 тысячи), сутки — под 86 тысяч. Retention у + таблицы нет, а `GET /audit/accounts` делает полный `GROUP BY` без фильтра по + времени. То же давление уходит на квоту проекта в GlitchTip — тот же + механизм вытеснения чужого сигнала, только в другом ведре. Дойдёт до этого — + окно агрегации растёт с длительностью атаки (экспонента с потолком, как у + `_throttle_delay_s`), это следующий шаг, а не сегодняшний. + """ + global _saturation_rejected, _saturation_reported_at + + _saturation_rejected += 1 + now = time.monotonic() + since_prev = None if _saturation_reported_at is None else now - _saturation_reported_at + if since_prev is None or since_prev >= _SATURATION_REPORT_WINDOW_S: + rejected, _saturation_rejected = _saturation_rejected, 0 + _saturation_reported_at = now + logger.error( + "login rejected: password verify saturated — %d отказов, " + "с прошлой записи %s с, последний ip=%s", + rejected, + "—" if since_prev is None else f"{since_prev:.1f}", + ip, + ) + schedule_event( + event_type="login_verify_saturated", + username="", + ip=ip, + path="/api/v1/auth/login", + method="POST", + payload={ + "rejected": rejected, + # Считается ДО сдвига `_saturation_reported_at` — иначе всегда 0. + "since_prev_s": None if since_prev is None else round(since_prev, 1), + }, + ) + + # Retry-After 1с — порядок времени одной сверки, не окно соседнего + # `_LOGIN_LIMITER`. Ответ ОДИН И ТОТ ЖЕ для любого имени: отказ приходит до + # сверки и потому ничего не сообщает о том, существует ли учётка. + return HTTPException( + status_code=429, + detail="слишком много попыток входа, попробуйте позже", + headers={"Retry-After": "1"}, + ) + + async def _reject_invalid_credentials( db: Session, username: str, ip: str, user_agent: str | None ) -> HTTPException: @@ -256,6 +375,16 @@ async def login( headers={"Retry-After": str(int(retry_after) + 1)}, ) + # Гейт насыщения — ДО выборки из реестра (#2715). Заведомо отклоняемый + # запрос не берёт соединение из пула и не делает SELECT по имени: под + # насыщением это была бы единственная работа на пути отказа, а значит и + # единственное, чьё время зависит от существования учётки — bcrypt, который + # эту разницу ровняет, до отказанного запроса не доходит вовсе. Решение + # всё равно остаётся за `verify_password_bounded` ниже (тот же предикат, + # `except` под ним никуда не делся) — здесь только экономия похода в базу. + if verify_slots_saturated(ip): + raise _saturated_429(ip) + user = get_user_by_username(db, body.username) hash_to_check = ( user["password_hash"] @@ -274,17 +403,11 @@ async def login( password_ok = await verify_password_bounded(body.password, hash_to_check, key=ip) except PasswordVerifyOverloadedError: # Настоящий потолок темпа (#2665): слоты проверки заняты, ждать нельзя — - # ждущий держит соединение к БД. Отказ ОДИНАКОВ для любого имени и - # случается ДО сверки, поэтому оракулом существования учётки не служит и - # бюджет неудач по имени не тратит (это не попытка входа: пароль не - # проверялся). Retry-After 1с — порядок времени одной проверки, не окно - # соседнего `_LOGIN_LIMITER`. - logger.warning("login rejected: password verify saturated ip=%s", ip) - raise HTTPException( - status_code=429, - detail="слишком много попыток входа, попробуйте позже", - headers={"Retry-After": "1"}, - ) from None + # ждущий держит соединение к БД. Предчек выше сюда почти всё и отсекает, + # но авторитетен ИМЕННО ЭТОТ отказ, поэтому ветка остаётся. Ответ — + # тот же самый и с той же аргументацией, что у предчека: один helper, + # чтобы две ветки не разъехались (одинаковость 429 — часть защиты). + raise _saturated_429(ip) from None # Пароль проверен ВЫШЕ и безусловно — только теперь смотрим на состояние # доступа. Порядок несущий, а не стилистический: см. модульный docstring. diff --git a/tradein-mvp/backend/app/core/password.py b/tradein-mvp/backend/app/core/password.py index 2cec3ada..374d55a2 100644 --- a/tradein-mvp/backend/app/core/password.py +++ b/tradein-mvp/backend/app/core/password.py @@ -123,6 +123,32 @@ def _per_key_slot_cap() -> int: return max(1, settings.login_password_verify_max_inflight // 2) +def verify_slots_saturated(key: str) -> bool: + """Тот же предикат, по которому отказывает `verify_password_bounded`, но БЕЗ взятия слота. + + Нужен вызывающему ровно затем, чтобы отказать ДО похода в БД (#2715). Гейт + стоял ПОСЛЕ выборки пользователя, и каждый заведомо отклоняемый запрос всё + равно брал соединение из пула и делал SELECT по имени — тогда, когда система + уже перегружена. Хуже того, под насыщением эта выборка оставалась + ЕДИНСТВЕННОЙ работой на пути отказа: bcrypt, который ровняет время ответа + для существующего и несуществующего имени, ниже по течению и до него не + доходит, так что разницу «строка найдена / не найдена» ничто не маскировало. + + Предчек, а не решение: авторитетная проверка остаётся внутри + `verify_password_bounded` — она зовёт ЭТУ ЖЕ функцию, так что разъехаться + двум условиям нечем, и инвариант «одна точка выноса = одна точка учёта» + цел (слот здесь не резервируется и не отдаётся). + + Учитывает и общий потолок, и долю на ключ (#2714) — иначе предчек не + покрывал бы главный случай: при флуде с ОДНОГО адреса первым упирается + именно доля, и большинство отказов снова ходило бы в базу. + """ + return ( + _verify_inflight >= settings.login_password_verify_max_inflight + or _verify_inflight_by_key.get(key, 0) >= _per_key_slot_cap() + ) + + async def verify_password_bounded(plain: str, hashed: str, *, key: str) -> bool: """`verify_password`, унесённая с событийного цикла И с сознательным потолком темпа (#2665). @@ -193,9 +219,10 @@ async def verify_password_bounded(plain: str, hashed: str, *, key: str) -> bool: """ global _verify_inflight - if _verify_inflight >= settings.login_password_verify_max_inflight: - raise PasswordVerifyOverloadedError - if _verify_inflight_by_key.get(key, 0) >= _per_key_slot_cap(): + # АВТОРИТЕТНАЯ проверка. Вызывающий может спросить то же самое заранее + # (`verify_slots_saturated`, #2715), но решение принимается здесь и только + # здесь — предчек экономит поход в БД, а не заменяет этот отказ. + if verify_slots_saturated(key): raise PasswordVerifyOverloadedError loop = asyncio.get_running_loop() diff --git a/tradein-mvp/backend/tests/test_audit_api.py b/tradein-mvp/backend/tests/test_audit_api.py index 78ec6684..a3226678 100644 --- a/tradein-mvp/backend/tests/test_audit_api.py +++ b/tradein-mvp/backend/tests/test_audit_api.py @@ -53,6 +53,39 @@ def test_days_param_uses_cast_as_int() -> None: assert "CAST(:days AS int)" in _AUDIT_SRC +def test_every_group_by_username_filters_out_the_nameless() -> None: + """Каждая выборка «по аккаунтам» отбрасывает строки с пустым именем (#2715). + + Пустое имя пишет `login_verify_saturated`: отказ по насыщению случается ДО + того, как мы посмотрели на присланное имя, и записать его нельзя — иначе + атакующий набивал бы аудит строками с любым именем на выбор. Но аккаунтом + такая строка от этого не становится: без фильтра она встаёт ПЕРВОЙ в списке + (её `last_seen_at` — момент атаки), даёт фантома в `count(DISTINCT + username)`, а раскрытие уходит в `/audit/accounts/{username}` с + `min_length=1` — то есть в ошибку. + + То же и со счётчиками уникальных: `count(DISTINCT username)` считал бы + безымянного за человека, и первая же атака НАВСЕГДА добавила бы +1 к числу + пользователей (строка остаётся в таблице). `NULLIF(username, '')` роняет её + в NULL, который `count(DISTINCT)` не считает. Сами события при этом из + `total_events` не исчезают — они события, просто не люди. + + Сравнение ЧИСЛОМ, а не поиском подстроки: так сторож ловит и НОВУЮ выборку, + добавленную без фильтра, а не только сегодняшние. На проде пустых имён + сейчас 0 из 3365 строк — то есть это ново. + """ + grouped = _AUDIT_SRC.count("GROUP BY username") + filtered = _AUDIT_SRC.count("WHERE username <> ''") + assert grouped == filtered, ( + f"{grouped} выборок GROUP BY username, из них с фильтром {filtered} — " + "безымянная строка попадёт в список аккаунтов" + ) + assert "count(DISTINCT username)" not in _AUDIT_SRC, ( + "count(DISTINCT username) считает безымянные события за людей — " + "нужен count(DISTINCT NULLIF(username, ''))" + ) + + # --------------------------------------------------------------------------- # Fakes — mirror the mocked-DB convention used across tests/test_user_events.py etc. # --------------------------------------------------------------------------- diff --git a/tradein-mvp/backend/tests/test_auth_api.py b/tradein-mvp/backend/tests/test_auth_api.py index 090b9422..17b0930e 100644 --- a/tradein-mvp/backend/tests/test_auth_api.py +++ b/tradein-mvp/backend/tests/test_auth_api.py @@ -32,6 +32,7 @@ in-memory fake DB standing in for the identity registry: from __future__ import annotations import asyncio +import logging import os import re import time @@ -259,6 +260,10 @@ def _reset_state(monkeypatch: pytest.MonkeyPatch) -> None: auth_mod.reset_cache_for_tests() auth_router._LOGIN_LIMITER._hits.clear() auth_router._USERNAME_FAIL_LIMITER._hits.clear() + # Агрегатор отказов по насыщению (#2715) — тоже глобал процесса: без сброса + # недосчитанные отказы одного теста всплывают в записи другого. + monkeypatch.setattr(auth_router, "_saturation_rejected", 0) + monkeypatch.setattr(auth_router, "_saturation_reported_at", None) monkeypatch.setattr(config.settings, "auth_mode", "dual") # Каждый тест стартует в ДЕФОЛТНОМ режиме реестра (сегодняшний прод), даже # если предыдущий переключался на `auth`. @@ -958,6 +963,183 @@ async def test_flood_from_one_ip_leaves_login_open_for_another_ip( ) +# --------------------------------------------------------------------------- +# #2715 — отказ по насыщению: до похода в БД и со следом, который не выселяет лог +# --------------------------------------------------------------------------- + + +def _saturate_verify_slots(monkeypatch: pytest.MonkeyPatch) -> None: + """Слоты сверки заняты — снаружи ровно то же, что живой флуд, но без гонок. + + Именно счётчик, а не мок `verify_password_bounded`: проверяем настоящий + предикат отказа (`verify_slots_saturated` читает этот же глобал), а не + собственную заглушку. + """ + monkeypatch.setattr(password_mod, "_verify_inflight", 999) + + +def test_saturated_login_answers_before_touching_the_registry( + client: TestClient, store: _Store, monkeypatch: pytest.MonkeyPatch +) -> None: + """Под насыщением отказ приходит ДО выборки пользователя (#2715). + + Гейт стоял после SELECT'а, и каждый заведомо отклоняемый запрос всё равно + брал соединение из пула — тогда, когда система уже перегружена. Хуже того, + эта выборка оставалась ЕДИНСТВЕННОЙ работой на пути отказа: bcrypt, ровняющий + время ответа для существующего и несуществующего имени, до отказанного + запроса не доходит вовсе, так что разницу маскировать было нечем. + + Мерим не тайминг (в CI флейкует), а сам факт похода в реестр — и заодно + побайтовую одинаковость ответа для живого и выдуманного имени. + """ + store.add_user("alice", hash_password("Secret123!"), role="employee") + _capture_events(monkeypatch) + + lookups: list[str] = [] + real_lookup = auth_router.get_user_by_username + + def _spy(db: Any, username: str) -> Any: + lookups.append(username) + return real_lookup(db, username) + + monkeypatch.setattr(auth_router, "get_user_by_username", _spy) + _saturate_verify_slots(monkeypatch) + + bodies = [] + for name in ("alice", "ghost"): + resp = client.post( + "/api/v1/auth/login", + json={"username": name, "password": "x"}, + headers={"x-forwarded-for": "203.0.113.5"}, + ) + assert resp.status_code == 429, resp.text + assert resp.headers["Retry-After"] == "1" + bodies.append(resp.text) + + assert lookups == [], f"под насыщением всё-таки сходили в реестр: {lookups}" + # Существующее и несуществующее имя — неразличимы (#2571 на этом пути тоже). + assert bodies[0] == bodies[1] + + +def test_key_share_alone_also_answers_before_the_registry( + client: TestClient, store: _Store, monkeypatch: pytest.MonkeyPatch +) -> None: + """Долю на ключ предчек проверяет ТОЖЕ — и это главный случай, а не запасной. + + Соседний тест занимает ОБЩИЙ счётчик, а `or` в `verify_slots_saturated` + коротит на первой половине: выброси вторую — и тот тест останется зелёным. + Между тем при флуде с ОДНОГО адреса (#2714) общий потолок не выбирается + вовсе, первой упирается именно доля, и без неё в базу ходили бы почти все + отклонённые запросы. + """ + store.add_user("alice", hash_password("Secret123!"), role="employee") + _capture_events(monkeypatch) + + lookups: list[str] = [] + real_lookup = auth_router.get_user_by_username + + def _spy(db: Any, username: str) -> Any: + lookups.append(username) + return real_lookup(db, username) + + monkeypatch.setattr(auth_router, "get_user_by_username", _spy) + # Общий котёл (4) НЕ выбран: занято 2 из 4, и оба — одним адресом. Это ровно + # его доля (`_per_key_slot_cap` = 4 // 2), больше ему не дают. + monkeypatch.setattr(password_mod, "_verify_inflight", 2) + monkeypatch.setattr(password_mod, "_verify_inflight_by_key", {"203.0.113.5": 2}) + assert password_mod._per_key_slot_cap() == 2 # исходные условия теста + + flooder = client.post( + "/api/v1/auth/login", + json={"username": "alice", "password": "x"}, + headers={"x-forwarded-for": "203.0.113.5"}, + ) + assert flooder.status_code == 429, flooder.text + assert lookups == [], f"доля исчерпана, а в реестр всё-таки сходили: {lookups}" + + # И тут же — доказательство, что предчек не отказывает всем подряд: с + # ДРУГОГО адреса свободные слоты есть, запрос идёт дальше, в реестр. + other = client.post( + "/api/v1/auth/login", + json={"username": "alice", "password": "wrong"}, + headers={"x-forwarded-for": "198.51.100.10"}, + ) + assert other.status_code == 401, other.text + assert lookups == ["alice"] + + +def test_saturation_is_reported_once_per_window_and_lands_in_audit( + client: TestClient, store: _Store, monkeypatch: pytest.MonkeyPatch, caplog: Any +) -> None: + """Двадцать отказов — одна запись в лог и одно событие в аудит, со счётчиком. + + Строка на каждый отказ делила с остальным бэкендом `json-file max-size 20m × + max-file 3`: при флуде в сотни запросов в секунду 60 МБ прокручиваются за + минуты и выселяют ВСЕ остальные логи ровно во время атаки. Поэтому окно. + + А событие в `user_events` — потому что до #2715 инцидент не оставлял в + аудите ни строчки: событие неудачного входа тут не пишется намеренно + (пароль не проверялся, и трата бюджета неудач дала бы блокировку чужой + учётки насыщением) — значит нужен отдельный тип события, и он обязан + появляться независимо от того, ротировался лог или нет. + """ + # ЛИТЕРАЛ, а не арифметика от настройки: окно — компромисс «видно вовремя» + # против «не выселяет лог», и подъём его до минут прячет атаку целиком. + assert auth_router._SATURATION_REPORT_WINDOW_S == 1.0 + + events = _capture_events(monkeypatch) + _saturate_verify_slots(monkeypatch) + # Окно на весь тест — иначе медленный CI разбил бы 20 запросов на два окна + # и число записей стало бы функцией скорости раннера. + monkeypatch.setattr(auth_router, "_SATURATION_REPORT_WINDOW_S", 60.0) + caplog.set_level(logging.WARNING, logger="app.api.v1.auth") + + for i in range(20): + resp = client.post( + "/api/v1/auth/login", + json={"username": f"ghost{i}", "password": "x"}, + headers={"x-forwarded-for": "203.0.113.5"}, + ) + assert resp.status_code == 429, resp.text + + lines = [r for r in caplog.records if "saturated" in r.getMessage()] + assert len(lines) == 1, f"20 отказов дали {len(lines)} строк в логе — агрегации нет" + # ERROR, а не WARNING: бэкенд поднят с LoggingIntegration(event_level=ERROR) + # (app/main.py), и только с ERROR запись становится событием GlitchTip. + # Понижение уровня выключило бы канал молча — прецедент #2674. + assert lines[0].levelno == logging.ERROR + + saturated = [e for e in events if e["event_type"] == "login_verify_saturated"] + assert len(saturated) == 1, saturated + # Первый отказ отчитывается сразу (одиночная аномалия обязана быть видна), + # поэтому в первой записи он один — накопленное придёт следующей. + assert saturated[0]["payload"] == {"rejected": 1, "since_prev_s": None} + assert saturated[0]["ip"] == "203.0.113.5" + # Имя не пишем: отказ случился ДО того, как мы на него посмотрели, а запись + # присланного дала бы атакующему аудит-строки с любым именем на выбор. + assert saturated[0]["username"] == "" + + # Бюджет неудач по имени не тронут — иначе насыщением блокируют чужой вход. + assert [e for e in events if e["event_type"] == "login_failed"] == [] + assert not auth_router._USERNAME_FAIL_LIMITER._hits + + # Окно прошло — следующий отказ приносит НАКОПЛЕННОЕ, а не единицу. + monkeypatch.setattr(auth_router, "_saturation_reported_at", time.monotonic() - 61.0) + resp = client.post( + "/api/v1/auth/login", + json={"username": "ghost-last", "password": "x"}, + headers={"x-forwarded-for": "203.0.113.5"}, + ) + assert resp.status_code == 429 + saturated = [e for e in events if e["event_type"] == "login_verify_saturated"] + assert len(saturated) == 2 + assert saturated[1]["payload"]["rejected"] == 20, "счётчик за окно потерян" + # Без этого числа 20 отказов читались бы как «20 за секунду», хотя копились + # они минуту: хвост уезжает в запись, датированную моментом СЛЕДУЮЩЕГО + # отказа и подписанную ЕГО адресом — возможно, случайного соседа по NAT. + assert saturated[1]["payload"]["since_prev_s"] == pytest.approx(61.0, abs=1.0) + + # --------------------------------------------------------------------------- # POST /logout # ---------------------------------------------------------------------------