diff --git a/tradein-mvp/backend/tests/test_auth_api.py b/tradein-mvp/backend/tests/test_auth_api.py index 9436d1f7..ab5c5880 100644 --- a/tradein-mvp/backend/tests/test_auth_api.py +++ b/tradein-mvp/backend/tests/test_auth_api.py @@ -35,6 +35,7 @@ import asyncio import logging import os import re +import threading import time from datetime import UTC, datetime, timedelta from types import SimpleNamespace @@ -763,14 +764,19 @@ async def test_login_flood_capped_by_rate_while_api_stays_responsive( app = _build_test_app(store) attempts: list[float] = [] + verify_threads: set[int] = set() def _slow_verify(plain: str, hashed: str) -> bool: """Стенд-двойник bcrypt: столько же БЛОКИРУЮЩЕГО времени, только меньше. Блокирующий `time.sleep`, а не `await` — суть проблемы в том, что bcrypt не отпускает поток; двойник с `await` проверял бы не то. + + Заодно записывает ПОТОК исполнения: это и есть механизм выноса (#3343) — + величина дискретная, от загрузки раннера не зависящая. """ attempts.append(time.monotonic()) + verify_threads.add(threading.get_ident()) time.sleep(verify_s) return False @@ -824,19 +830,38 @@ async def test_login_flood_capped_by_rate_while_api_stays_responsive( # Проверяется ПЕРВЫМ: если цикл занят, встаёт и сам флуд, и тогда # остальные числа мерят не потолок, а паралич — их надо читать после # этого вердикта, а не вместо него. - assert probe_latencies, "проба не сделала ни одного запроса" + # + # Вердикт — про МЕХАНИЗМ, а не про секундомер (#3343). Раньше здесь стоял + # абсолютный порог латентности пробы (`худший < 500мс`, `медиана < 50мс`). + # На общем раннере он мерил не свойство кода, а свободен ли CPU у соседей: + # 03.09 деплой встал на «худший сторонний запрос 544мс» ровно на том + # коммите, который часом раньше прошёл на незанятой машине. Порог, который + # краснеет от чужой параллельной сборки, не отличает поломку от нагрузки, + # а красный обязан значить «значение неверно», иначе его начинают + # переспрашивать. Обе замены переживают любую загрузку: + # - ПОТОК, в котором исполнилась сверка, — величина дискретная. Вернись + # bcrypt в `async def` — здесь окажется поток цикла, и никакой простой + # раннера этого не замаскирует и не подделает; + # - ТИКИ пробы: цикл с bcrypt внутри стоит практически всю секунду + # флуда (сверки идут подряд по 50мс), и проба не успевает почти + # никогда; при выносе в пул она просыпается раз в 10мс, то есть ~100 + # раз. Порог 10 лежит в середине этого разрыва с запасом ×10 в обе + # стороны — на общем раннере съедается пропускная способность, но не + # порядок величины. + # Сами латентности остаются в сообщении как ДИАГНОСТИКА: числа полезны, + # когда тест красный, и не годятся в вердикт, пока машина общая. + assert verify_threads, "ни одной сверки пароля не состоялось — мерить нечего" + assert threading.get_ident() not in verify_threads, ( + "сверка пароля исполнилась в потоке событийного цикла — bcrypt держит весь " + "API на всё время проверки (вынос в пул из #2665 отменён)" + ) + assert probe_latencies, "проба не сделала ни одного запроса — цикл был занят" probe_latencies.sort() - assert probe_latencies[-1] < 0.5, ( - f"худший сторонний запрос {probe_latencies[-1] * 1000:.0f}мс — API встаёт под флудом входа" - ) median_probe = probe_latencies[len(probe_latencies) // 2] - assert median_probe < verify_s, ( - f"медиана стороннего запроса {median_probe * 1000:.0f}мс ≥ времени одной " - f"сверки — цикл занят проверкой пароля, API стоит" - ) - # Мало проб за секунду — тоже занятый цикл: проба просыпается раз в 10мс. assert len(probe_latencies) >= 10, ( - f"проба успела всего {len(probe_latencies)} раз за {elapsed:.2f}с — цикл был занят" + f"проба успела всего {len(probe_latencies)} раз за {elapsed:.2f}с " + f"(медиана {median_probe * 1000:.0f}мс, худший {probe_latencies[-1] * 1000:.0f}мс) " + f"— цикл был занят" ) # 2. ТЕМП ограничен. Флуд предлагал больше попыток в секунду, чем разрешает