fix(tradein/auth): хвост счётчика датируется честно, безымянное событие — не аккаунт (#2715)
All checks were successful
CI Trade-In / browser-tests (pull_request) Has been skipped
CI Trade-In / frontend-checks (pull_request) Has been skipped
CI / backend-tests (pull_request) Has been skipped
CI / frontend-tests (pull_request) Has been skipped
CI Trade-In / backend-tests (pull_request) Successful in 3m8s
CI / changes (pull_request) Successful in 8s
CI Trade-In / changes (pull_request) Successful in 9s
CI / openapi-codegen-check (pull_request) Has been skipped

Три правки по ревью PR #2734.

1. `since_prev_s` в payload события. Хвост отказов копится, пока не придёт
   следующий: атака кончилась в 03:00, 900 отказов не отчитаны — и во вторник
   одиночный 429 соседа по NAT унёс бы их все в запись, датированную вторником и
   подписанную АДРЕСОМ СОСЕДА. По `created_at` это читалось бы как 901 отказ в
   моменте. Теперь видно, за какой промежуток они накоплены (None — первая
   запись за жизнь процесса, сравнивать не с чем); считается ДО сдвига отметки,
   иначе всегда 0 — проверено мутацией.

2. Безымянная строка больше не притворяется аккаунтом. `WHERE username <> ''`
   в обеих выборках `GROUP BY username` (audit.py): без фильтра строка встала бы
   ПЕРВОЙ в списке аккаунтов (её last_seen_at — момент атаки), а её кнопка в UI
   раскрывалась бы в /audit/accounts/{username} с min_length=1, то есть в
   ошибку. Плюс `count(DISTINCT NULLIF(username, ''))` в трёх счётчиках
   уникальных: строка остаётся в таблице навсегда, значит и +1 к числу
   пользователей был бы навсегда. Из total_events события при этом не исчезают —
   они события, просто не люди. Все четыре изменённые выборки прогнаны на проде
   read-only: синтаксис живой.

3. Дыра в покрытии: ветку «доля на ключ» в предчеке не исполнял ни один тест —
   `or` коротил на общем счётчике, и вторую половину предиката можно было
   выкинуть незамеченной. Хотя отвечает она за главный реальный случай (флуд с
   одного адреса). Тест-близнец занимает долю ключа, а не общий котёл, и
   проверяет заодно, что с ДРУГОГО адреса запрос идёт дальше.

Масштаб назван в docstring рядом с прочими потолками: час непрерывной атаки =
3600 строк в user_events (за всю жизнь таблицы ~3.4 тысячи), сутки — под 86
тысяч, retention нет; то же давление уходит на квоту GlitchTip.

Refs #2715
This commit is contained in:
bot-backend 2026-08-06 19:22:41 +05:00
parent 8958a657cb
commit 18bfa7d3cb
4 changed files with 137 additions and 20 deletions

View file

@ -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

View file

@ -194,12 +194,12 @@ def _throttle_delay_s(fails_in_window: int) -> float:
# ухудшает разрешение по времени, не давая взамен ничего.
_SATURATION_REPORT_WINDOW_S = 1.0
# Отказов с прошлой записи и когда была прошлая запись (monotonic). Обычные
# глобалы без лока — по той же причине, что и счётчик слотов в
# `app.core.password`: обе строчки исполняются в потоке событийного цикла и
# между чтением и записью нет `await`.
# Отказов с прошлой записи и когда была прошлая запись (monotonic; None — записи
# ещё не было). Обычные глобалы без лока — по той же причине, что и счётчик
# слотов в `app.core.password`: обе строчки исполняются в потоке событийного
# цикла и между чтением и записью нет `await`.
_saturation_rejected = 0
_saturation_reported_at = 0.0
_saturation_reported_at: float | None = None
def _saturated_429(ip: str) -> HTTPException:
@ -214,11 +214,17 @@ def _saturated_429(ip: str) -> HTTPException:
Поэтому на окно приходится одна строка в лог И одно событие
`login_verify_saturated` в `user_events` с числом отказов, накопленных с
прошлой записи. Событие важнее строки: аудит переживает и ротацию логов, и
редеплой, а по `created_at` соседних строк восстанавливается темп атаки
(сколько прошло между записями), поэтому длительность окна в payload не
дублируется. Первый отказ отчитывается сразу, а не в конце окна: одиночная
редеплой. Первый отказ отчитывается сразу, а не в конце окна: одиночная
аномалия обязана быть видна, даже если продолжения не будет.
`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 остаётся
@ -234,22 +240,34 @@ def _saturated_429(ip: str) -> HTTPException:
`username=""` не заглушка: имя не пишем ПОТОМУ, что отказ случился до
того, как мы на него посмотрели. Записывай мы присланное, атакующий
наполнял бы аудит строками с любым именем на выбор. `ip` адрес последнего
наполнял бы аудит строками с любым именем на выбор. Пустое имя не аккаунт,
и списки аудита его отфильтровывают (`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()
if now - _saturation_reported_at >= _SATURATION_REPORT_WINDOW_S:
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 отказов с прошлой записи "
"(не чаще раза в %.0fс), последний ip=%s",
"login rejected: password verify saturated — %d отказов, "
"с прошлой записи %s с, последний ip=%s",
rejected,
_SATURATION_REPORT_WINDOW_S,
"" if since_prev is None else f"{since_prev:.1f}",
ip,
)
schedule_event(
@ -258,7 +276,11 @@ def _saturated_429(ip: str) -> HTTPException:
ip=ip,
path="/api/v1/auth/login",
method="POST",
payload={"rejected": rejected},
payload={
"rejected": rejected,
# Считается ДО сдвига `_saturation_reported_at` — иначе всегда 0.
"since_prev_s": None if since_prev is None else round(since_prev, 1),
},
)
# Retry-After 1с — порядок времени одной сверки, не окно соседнего

View file

@ -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.
# ---------------------------------------------------------------------------

View file

@ -263,7 +263,7 @@ def _reset_state(monkeypatch: pytest.MonkeyPatch) -> None:
# Агрегатор отказов по насыщению (#2715) — тоже глобал процесса: без сброса
# недосчитанные отказы одного теста всплывают в записи другого.
monkeypatch.setattr(auth_router, "_saturation_rejected", 0)
monkeypatch.setattr(auth_router, "_saturation_reported_at", 0.0)
monkeypatch.setattr(auth_router, "_saturation_reported_at", None)
monkeypatch.setattr(config.settings, "auth_mode", "dual")
# Каждый тест стартует в ДЕФОЛТНОМ режиме реестра (сегодняшний прод), даже
# если предыдущий переключался на `auth`.
@ -1021,6 +1021,53 @@ def test_saturated_login_answers_before_touching_the_registry(
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:
@ -1066,7 +1113,7 @@ def test_saturation_is_reported_once_per_window_and_lands_in_audit(
assert len(saturated) == 1, saturated
# Первый отказ отчитывается сразу (одиночная аномалия обязана быть видна),
# поэтому в первой записи он один — накопленное придёт следующей.
assert saturated[0]["payload"] == {"rejected": 1}
assert saturated[0]["payload"] == {"rejected": 1, "since_prev_s": None}
assert saturated[0]["ip"] == "203.0.113.5"
# Имя не пишем: отказ случился ДО того, как мы на него посмотрели, а запись
# присланного дала бы атакующему аудит-строки с любым именем на выбор.
@ -1086,7 +1133,11 @@ def test_saturation_is_reported_once_per_window_and_lands_in_audit(
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}, "счётчик за окно потерян"
assert saturated[1]["payload"]["rejected"] == 20, "счётчик за окно потерян"
# Без этого числа 20 отказов читались бы как «20 за секунду», хотя копились
# они минуту: хвост уезжает в запись, датированную моментом СЛЕДУЮЩЕГО
# отказа и подписанную ЕГО адресом — возможно, случайного соседа по NAT.
assert saturated[1]["payload"]["since_prev_s"] == pytest.approx(61.0, abs=1.0)
# ---------------------------------------------------------------------------