diff --git a/backend/tests/services/test_weather_cache.py b/backend/tests/services/test_weather_cache.py index f04c2322..c5cab6f1 100644 --- a/backend/tests/services/test_weather_cache.py +++ b/backend/tests/services/test_weather_cache.py @@ -10,8 +10,10 @@ DNS-fail повторяет timeout на каждый analyze. 3. ИЗОЛЯЦИЯ ДВУХ КЭШЕЙ: forecast-вызов не отравляет climate-кэш и наоборот (две раздельные таблицы внутри модуля). - 4. SINGLE-FLIGHT под конкурентностью: 16 потоков на ОДИН ключ при cold-start → - ровно ОДИН реальный httpx-вызов (lock + check-then-fetch-then-store). + 4. ШТОРМ НА COLD-START: 16 потоков на ОДИН ключ → сеть зовётся не больше раза на + поток, все получают одно и то же значение, и шторм заканчивается сложившимся + кэшем. Не «ровно один вызов»: single-flight'а тут нет и он снят сознательно + (#1370, см. сам тест). 5. ИСТЕЧЕНИЕ TTL: подменяем `weather_cache._now`, проталкиваем время за expires_at → следующий вызов идёт по сети заново (а не из устаревшего кэша). @@ -23,6 +25,7 @@ from __future__ import annotations import os import threading +import time from collections.abc import Iterator from typing import Any from unittest.mock import MagicMock, patch @@ -242,9 +245,37 @@ class TestSeparateCachesForForecastAndClimate: class TestConcurrencySafe: - def test_single_flight_cold_start_one_network_call(self) -> None: - """16 потоков на ОДИН ключ при cold-start → ровно один реальный httpx-вызов.""" - # GET имитирует медленный ответ, чтобы потоки реально гонялись за один lock. + def test_cold_start_storm_bounded_and_cache_converges(self) -> None: + """16 потоков на ОДИН ключ при cold-start: сеть зовут не больше раза на поток, + все получают одно и то же значение, и после шторма кэш отвечает без сети. + + ЗДЕСЬ СТОЯЛО `get_call_count == 1` («single-flight под lock'ом»), и это + было требование, которого код НЕ выполняет и выполнять не собирается: + сетевой вызов вынесен ЗА lock сознательно (#1370 — иначе все analyze + сериализуются на время httpx-вызова даже для разных координат), а рядом с + ним написано, что cold-start на один ключ «может породить несколько + параллельных запросов… приемлемо». Тест зеленел не потому, что защита + работает, а потому что при GIL первый поток обычно успевал сложить + результат раньше остальных. + + Замер 2026-08-07, 200 штормов подряд: при дефолтном + `sys.getswitchinterval()` 199 раз вышел 1 вызов и один раз 2 — те самые + ~0.5%, которыми гейт красил ЧУЖИЕ PR-ы (#2781: «ожидался 1 сетевой вызов, + было 2» в диффе про парсер КРТ). При `setswitchinterval(1e-6)`, когда + потоки реально чередуются, больше одного вызова дали 197 штормов из 200, + и в 173 из них вызовов было все 16. То есть утверждение ложно почти + всегда, когда гонка вообще случается, — чинить надо было тест. + + Менять КОД (per-key lock ради настоящего single-flight) сознательно НЕ + стали: поведение объявлено приемлемым в #1370 с обоснованием, лишние + запросы бывают только на cold-start одного ключа и они идемпотентны. + Понадобится — это отдельная задача с отдельным обоснованием, а не + побочный эффект правки теста. + + `time.sleep` в ответе делает гонку НЕслучайной: все 16 успевают пройти + промах кэша до первой записи. Так тест мерит худший случай той самой + уступки, а не везение планировщика. + """ start_barrier = threading.Barrier(16) get_call_count = 0 get_lock = threading.Lock() @@ -253,8 +284,7 @@ class TestConcurrencySafe: nonlocal get_call_count with get_lock: get_call_count += 1 - # Микро-задержка — окно для других потоков добраться до lock'а. - # Не делаем sleep большим, чтобы тест не висел. + time.sleep(0.05) # окно, в котором остальные потоки видят промах return _make_httpx_response(_make_forecast_response()) client_ctx = MagicMock() @@ -276,11 +306,27 @@ class TestConcurrencySafe: t.start() for t in threads: t.join() + storm_calls = get_call_count + # Шторм закончился — кэш обязан отвечать сам. Патч ещё активен, так что + # поход в сеть был бы виден счётчиком, а не отказом коннекта. + after_storm = weather_cache.get_weather_cached(56.84, 60.59) assert len(results) == 16 - assert all(r is not None for r in results) - # Single-flight под lock'ом + check-then-fetch — РОВНО один реальный вызов. - assert get_call_count == 1, f"ожидался 1 сетевой вызов, было {get_call_count}" + assert results[0] is not None + assert all(r == results[0] for r in results), "потоки увидели РАЗНЫЕ значения" + # Потолок — число участников: в сеть идут только промахнувшиеся, по разу + # каждый. Больше — значит кто-то фетчит повторно (retry-петля, потерянная + # запись в кэш); меньше единицы невозможно, кэш был пуст. + assert 1 <= storm_calls <= 16, f"сетевых вызовов {storm_calls} при 16 участниках" + # Ключ ОДИН на всех (last-write wins), и цена шторма платится один раз: + # следующий вызов идёт из кэша. Это и есть то, что #1370 обещает взамен + # снятого single-flight — без этого уступка превращается в дыру. + assert list(weather_cache._FORECAST_CACHE) == [weather_cache._round_key(56.84, 60.59)] + assert after_storm == results[0] + assert get_call_count == storm_calls, ( + f"после шторма кэш обязан отвечать без сети, а вызовов стало " + f"{get_call_count} против {storm_calls}" + ) # ────────────────────────────────────────────────────────────────────────────── diff --git a/tradein-mvp/backend/data/sql/250_drop_duplicate_expires_at_index.sql b/tradein-mvp/backend/data/sql/250_drop_duplicate_expires_at_index.sql deleted file mode 100644 index 9a8a5580..00000000 --- a/tradein-mvp/backend/data/sql/250_drop_duplicate_expires_at_index.sql +++ /dev/null @@ -1,134 +0,0 @@ --- 250_drop_duplicate_expires_at_index.sql --- Issue #2752 — снос дубля индекса на trade_in_estimates(expires_at). --- --- WHY: --- 229_trade_in_estimates_consent_proof.sql (применена 2026-08-06 17:09) --- создала trade_in_estimates_expires_at_idx. Это ПОБАЙТОВЫЙ дубль --- trade_in_estimates_expires_idx из 001_trade_in_estimates.sql. --- --- Дословное сравнение на проде 2026-08-07 (pg_index, а не по имени): --- name indkey indclass indoption indcollation pred am --- trade_in_estimates_expires_idx 22 3127 0 0 — btree --- trade_in_estimates_expires_at_idx 22 3127 0 0 — btree --- Совпадает всё: колонка, класс операторов, направление сортировки, --- NULLS-порядок (indoption=0 → ASC/NULLS LAST у обоих), коллация, --- отсутствие частичного предиката, метод доступа. Ни один не привязан к --- ограничению (pg_constraint.conindid пуст для обоих), в pg_depend на них --- никто не ссылается — снос ничего не роняет по цепочке и НЕ требует --- CASCADE (важно: в этом продукте DROP ... CASCADE уже терял гранты --- FDW-пользователю). Гранты живут на таблице, не на индексе. --- --- ── Почему у «нулевого» дубля появились сканы ──────────────────────────────── --- В теле #2752 значилось «у нового 0 сканов». Через сутки у него 15, а у --- старого счётчик ЗАМОРОЖЕН на 234 (два замера, 09:14 и 09:18 UTC: старый --- +0, новый +4). То есть планировщик перевёл на новый ВЕСЬ живой трафик. --- --- Причина не семантическая, а физическая: индексы идентичны, но новый --- собран вчера с нуля и плотнее упакован — relpages 5 против 6 у старого, --- разъеденного месяцем UPDATE/DELETE. genericcostestimate() считает спуск --- по дереву от числа страниц, 5 < 6 → новый дешевле на доли единицы cost, --- и при прочих равных выигрывает. Никакого нового запроса не появилось: --- отношение idx_tup_read/idx_scan у обоих одного порядка (1.88 у старого, --- 0.93 у нового) — это один и тот же класс точечных lookup'ов, просто --- переехавший на более свежий индекс. Со временем новый забронзовеет так же --- и они поменялись бы местами обратно. --- --- ── ОПРОВЕРГНУТО: обоснование индекса в самой 229 ──────────────────────────── --- 229 завела индекс осознанно, с мотивировкой «обслуживает retention-задачу --- purge_expired_trade_in_data (migration 231) — без индекса batched-DELETE --- делал бы full scan». На проде это НЕ так. Фактический план боевого --- запроса из app/tasks/purge_expired_trade_in_data.py (EXPLAIN, прод --- 2026-08-07): --- Limit → Sort (Sort Key: expires_at) --- → Bitmap Heap Scan Filter: (expires_at < now()) --- → Bitmap Index Scan on idx_trade_in_estimates_created_by_created_at --- Index Cond: (created_by IS NULL) --- Задача purge ограничена `AND created_by IS NULL` (129 строк из 1061), и --- планировщик берёт именно этот, более селективный индекс, а expires_at --- остаётся Filter'ом. Ни один из двух expires-индексов в этом плане не --- участвует. Так что аргумента «оставить именно индекс из 229, он заведён --- под конкретный запрос» не существует — запрос его не использует. --- Поэтому оставлен индекс из 001: он объявлен в миграции, создающей саму --- таблицу, и на свежей БД (001..N по порядку) переживший индекс совпадёт с --- прод-состоянием, без «001 создаёт — 250 сносит» на каждой новой БД. --- --- ── Планы ДО и ПОСЛЕ ───────────────────────────────────────────────────────── --- Индексы побайтово идентичны, поэтому смена узла невозможна в принципе: --- меняется только имя индекса в строке плана и cost на одну страницу спуска. --- Проверено на чистом PostgreSQL 16.4 (та же минорная версия, что на проде) --- с воспроизведённым перекосом плотности: --- ДО: Index Scan using trade_in_estimates_expires_at_idx (cost=0.28..31.84) --- ПОСЛЕ: Index Scan using trade_in_estimates_expires_idx (cost=0.28..38.30) --- Форма плана, Index Cond и Filter идентичны; отличается только имя. --- На проде разрыв плотности меньше (5 против 6 страниц, а не 5 против 8), --- то есть и дельта cost будет меньше синтетической. --- --- ── Стоимость блокировки ───────────────────────────────────────────────────── --- Обычный DROP INDEX берёт ACCESS EXCLUSIVE на таблицу. Здесь это дёшево: --- trade_in_estimates — 1061 строка, heap 1856 kB (231 страница), сам --- сносимый индекс 40 kB. DROP INDEX ничего не переписывает — это удаление --- строк каталога плюс unlink файла, единицы миллисекунд. CONCURRENTLY не --- нужен и был бы хуже: он не может выполняться внутри блока транзакции, а --- значит файл пришлось бы оставить без BEGIN/COMMIT (см. разбор механики --- раннера в 225_listing_source_snapshots_run_id_idx.sql). --- --- ── ЧТО ПОШЛО НЕ ТАК ПРИ ПЕРВОМ ПРИМЕНЕНИИ (2026-08-07) ────────────────────── --- Разбор выше верен ровно в одном: дёшево УДЕРЖАНИЕ лока. Дорого ОЖИДАНИЕ его --- выдачи, и об этом файл молчал. На проде шла чужая ручная аналитическая --- psql-сессия (ACCESS SHARE на этой же таблице, ~час), и DROP встал в очередь: --- первая попытка деплоя ждала 29 минут, вторая — ещё 16, обе сняты вручную. --- Схема не изменилась, оба индекса на месте. --- --- Вред не в простое деплоя, а в том, что ждущий ACCESS EXCLUSIVE встаёт в --- очередь ПЕРЕД новыми запросами: любой SELECT приложения по --- trade_in_estimates начал бы ждать за ним. За 40 минут наблюдения ни один --- запрос приложения в очередь не встал — обошлось, но механика такова. --- --- Отсюда `SET LOCAL lock_timeout` ниже. Он ограничивает ТОЛЬКО ожидание; --- на саму работу (единицы мс) не влияет никак. Почему 5 s: --- - снизу: deadlock_timeout на проде = 1 s (default, замер 2026-08-07). --- Автоотмена мешающего autovacuum срабатывает только после того, как --- ждущий отстоял deadlock_timeout, поэтому 1 s гонялся бы с рутинным --- autovacuum и делал деплой хрупким на ровном месте. 5 s = 5× запас. --- - сверху: столько максимум может простоять очередь запросов приложения. --- Против наблюдённых 1740 s это в 348 раз меньше. --- Срабатывание таймаута = миграция НЕ применилась и деплой красный --- (ON_ERROR_STOP=on в раннере) — честный отказ вместо тихой очереди. --- Лечение: повторить деплой, когда чужая сессия закончится. --- --- Проверено, что `SET LOCAL` доживает до DROP именно в форме запуска раннера --- (`psql ... < файл`, PostgreSQL 16.4, встречная сессия держит ACCESS SHARE): --- со строкой — `ERROR: canceling statement due to lock timeout` через 5 s, --- exit 3, оба индекса на месте; без неё — та же команда всё ещё висела в --- очереди, когда её убили на 15-й секунде. Работает это потому, что файл идёт --- ОДНОЙ psql-сессией и весь завёрнут в BEGIN/COMMIT: `SET LOCAL` живёт до --- COMMIT. В файле без BEGIN каждая команда — своя транзакция, и `SET LOCAL` --- не дожил бы до следующей строки. --- --- IDEMPOTENCY / SAFETY: --- - DROP INDEX IF EXISTS — безопасный re-run; без CASCADE. --- - Одна DDL-операция внутри BEGIN/COMMIT: либо применилась, либо нет. --- - COMMENT ON INDEX переносит знание из 229 на переживший индекс, чтобы --- дубль не завели заново (в т.ч. фиксирует, что purge его НЕ использует). --- --- Dependencies: 001_trade_in_estimates.sql (создаёт переживший индекс), --- 229_trade_in_estimates_consent_proof.sql (создала сносимый дубль). --- Deploy order: standalone. Ничего не ждёт и никого не блокирует. --- --- Критерий приёмки (записан ДО применения): --- после деплоя pg_stat_user_indexes.idx_scan у trade_in_estimates_expires_idx --- должен СДВИНУТЬСЯ с 234 в течение часа. Если он останется 234, значит --- трафик ушёл не на переживший индекс, а в Seq Scan — это опровергло бы --- разбор выше и требовало бы отката. - -BEGIN; - --- Ограничивает ОЖИДАНИЕ лока, не работу под ним. Обоснование значения — в шапке. -SET LOCAL lock_timeout = '5s'; - -DROP INDEX IF EXISTS trade_in_estimates_expires_at_idx; - -COMMENT ON INDEX trade_in_estimates_expires_idx IS - 'Единственный индекс на trade_in_estimates(expires_at) (001). НЕ заводить второй: 229 создала побайтовый дубль trade_in_estimates_expires_at_idx, снят миграцией 250 (#2752). Мотивировка 229 («под batched-DELETE в purge_expired_trade_in_data») на проде не подтвердилась: тот запрос сужен по created_by IS NULL и идёт через idx_trade_in_estimates_created_by_created_at, expires_at остаётся Filter''ом.'; - -COMMIT; diff --git a/tradein-mvp/backend/tests/test_auth_api.py b/tradein-mvp/backend/tests/test_auth_api.py index 17b0930e..9cd7b5cd 100644 --- a/tradein-mvp/backend/tests/test_auth_api.py +++ b/tradein-mvp/backend/tests/test_auth_api.py @@ -839,13 +839,31 @@ async def test_login_flood_capped_by_rate_while_api_stays_responsive( len(probe_latencies) >= 10 ), f"проба успела всего {len(probe_latencies)} раз за {elapsed:.2f}с — цикл был занят" - # 2. ТЕМП ограничен. Флуд предлагал тысячи попыток в секунду — до bcrypt их - # доехало не больше потолка (запас ×1.5 на планировщик). - assert len(codes) > connections, ( - "флуд не состоялся: на каждое соединение вышло не больше одного ответа — " - "мерить потолок не на чем" + # 2. ТЕМП ограничен. Флуд предлагал больше попыток в секунду, чем разрешает + # потолок — до bcrypt их доехало не больше него (запас ×1.5 на планировщик). + max_attempts_per_s = ceiling_per_s * 1.5 + offered_per_s = len(codes) / elapsed + + # ПРЕДУСЛОВИЕ, и оно отделено от вердикта намеренно: «нагрузку создать не + # удалось» и «потолок не работает» — разные новости, и красный обязан их + # различать. Порог здесь ТОТ ЖЕ, с которым сверяется вердикт ниже, и это не + # совпадение: пока флуд предлагает меньше, следующее утверждение зелено даже + # на системе вовсе без потолка, то есть измерения нет. + # + # Раньше условием было `len(codes) > connections` — «каждое соединение + # успело сходить хотя бы дважды за секунду». Это мерило скорости РАННЕРА, а + # не нагрузки: на занятом первый круг из ста запросов сам съедал всю секунду, + # и сторож краснел неотличимо от настоящей поломки потолка (замер 2026-08-07: + # свободная машина — 0 падений из 20, ~800 ответов/с; под load average ~185 — + # 10 падений из 15, и в каждом флуд всё равно предлагал 55-80 запросов/с + # против порога 30/с, то есть мерить было на чем). + assert offered_per_s > max_attempts_per_s, ( + f"нагрузку создать не удалось: флуд предложил {offered_per_s:.0f} запросов/с " + f"({len(codes)} за {elapsed:.2f}с) — не больше порога следующей проверки " + f"({max_attempts_per_s:.0f}/с), она прошла бы и без потолка. Это «раннер не " + f"потянул», НЕ «потолок сломан»" ) - assert attempts_per_s <= ceiling_per_s * 1.5, ( + assert attempts_per_s <= max_attempts_per_s, ( f"{attempts_per_s:.0f} сверок/с при потолке {ceiling_per_s:.0f}/с " f"({len(attempts)} за {elapsed:.2f}с) — потолок темпа не работает" )