МЕРА: у запросов к БД появился потолок по времени и по ожиданию блокировки (#3463) #3508

Merged
bot-backend merged 2 commits from fix/3463-db-statement-timeout into main 2026-09-12 16:38:35 +00:00
Collaborator

Closes #3463

У движка app/core/db.py не было connect_args вовсе, а на боевой БД statement_timeout, lock_timeout и idle_in_transaction_session_timeout = 0 (сверено 12.09). После #3444/#3449 шаги БД на пути /estimate идут через обёртку, которая при отмене по бюджету дожидается своего потока — ожидание верное (иначе поток остаётся сиротой в общей Session), но его верхняя граница равна длительности самого запроса, а у запроса границы не было. Один ACCESS EXCLUSIVE на таблице → четыре повисших запроса → _ESTIMATE_CONCURRENCY = 4 исчерпан → /estimate отдаёт 429 всем остальным.

Потолок стоит на коннекте (libpq options), а не в обёртке: таймаут в обёртке вернул бы ровно ту сироту, ради которой писался #3449.

connect_args={"options": "-c statement_timeout=30000 -c lock_timeout=5000"}

Откуда величины

значение на чём основано
statement_timeout 30 000 мс 1.5× от самого длинного объявленного бюджета /estimate (20 с — estimate_avito_imv_timeout_s; дальше 12 с геокод, 8 с Yandex/Cian/house_meta). ~3× от самого длинного замеренного set-based statement'а через движок (матч ГАР→houses, 6.46 с). Выше самой долгой чисто-БД задачи планировщика (9.7 с целиком). Сверху ограничен тестом: <= 2 × объявленного бюджета.
lock_timeout 5 000 мс Та же величина, что у миграций проекта (SET LOCAL lock_timeout = '5s' в data/sql/250,251,260,272,277…), снизу ограничена deadlock_timeout = 1 с на проде. Именно этот потолок закрывает сценарий #3463: под ACCESS EXCLUSIVE запрос ждёт лок, а не считает.
idle_in_transaction_session_timeout не ставим Тем же движком живёт tgbot: services/tgbot/bridge.py держит транзакцию открытой поверх long-poll Telegram (замер 12.09, 3 пробы с шагом 7 с — одна и та же сессия, SELECT value FROM tg_support_state …, возраст транзакции циклически растёт до ~29 с). Сессионный потолок на простой ронял бы long-poll каждый цикл, гарантированно.

Замер на боевой БД (только SELECT, до правки)

Основная опора — scrape_runs (длительности целых прогонов; вытеснению не подвержены): самая долгая чисто-БД задача за 14 суток — listing_source_snapshot, 9.7 с целиком, весь остальной чисто-БД планировщик ≤ 8.8 с.

Самый длинный set-based statement через движок замерен отдельно — матч ГАР→houses (services/gar_flats_loader._MATCH_SQL, 919 341 строка gar_house_flats → 10 854 канона): 2.07 с с городским фильтром и 6.46 с без него (city_filter=None, доступен флагом CLI). Это CLI-задача, в scrape_runs её нет. Запас до потолка ~3×, и это считающий запрос, а не ждущий блокировку.

pg_stat_statements опорой по планировщику не является (правка после ревью): при max = 5000 он вытесняет редкие записи — проверено вживую 12.09, dealloc вырос 1020→1021 за десять минут, и из топа пропали все записи с calls = 1, включая REFRESH MATERIALIZED VIEW CONCURRENTLY (30.85 с) и KNN cadastral_geo_match (2.45 с). Суточная задача до следующих суток там не доживает. Поэтому «самый долгий запрос через движок 4.27 с» верно только для высокочастотных запросов — это и всё, за что этот источник отвечает:

  • запросов длиннее 20 с — 1, длиннее 5 с — 2, и оба идут мимо движка (REFRESH MATERIALIZED VIEW CONCURRENTLY 30.85 с — сырое psycopg.connect(); COPY _stg 19.67 с — psql из ручного scripts/local-avito-msk/collect.py);
  • максимум среди высокочастотных через движок — 4.27 с (WITH wd AS (… deals …), 401 вызов).

Задачи планировщика — по каждой вердикт

Движок один и тот же: scheduler_main.pyRealSessionFactoryapp.core.db.SessionLocal. Потолок накрывает и продуктовый путь, и планировщик, и все три сервиса образа (backend / scraper / tgbot).

задача / путь вердикт
listing_source_snapshot свой SET LOCALstatement_timeout = 900000 (tasks/listing_source_snapshot.py:288). Перекрытие сессионного потолка ПРОВЕРЕНО тестом, а не предположено. Сверх того укладывается: 9.7 с на прогон.
proxy_pool.attribute_run_proxy свой SET LOCALlock_timeout = '2s' (services/proxy_pool.py:513), строже нового потолка.
refresh_search_matview мимо движкаpsycopg.connect(dsn, autocommit=True). 30.85 с замерены, connect_args его не касается.
миграции data/sql/*.sql мимо движкаpsql из deploy-tradein.yml, у DDL свой SET LOCAL lock_timeout = '5s'.
свипы avito/cian/yandex/domclick, *_detail_backfill, geocode_missing_listings, proxy_healthcheck, newbuilding_enrich, house_imv_backfill укладываются — прогон идёт часами, но это питон-циклы коротких statement'ов + HTTP; statement_timeout действует НА STATEMENT, а не на транзакцию. Единственное, что их убило бы, — idle_in_transaction_session_timeout, и его мы не ставим.
rosreestr_dkp_import / _77 укладывается — FDW читается страницами по 2000 (batch_size), 428 statement'ов, max 629 мс; прогон 102 с целиком.
cadastral_geo_match укладывается — 4.2 с прогон; TRUNCATE cad_buildings_local 23 мс, INSERT … FROM FDW 748 мс, KNN-матч 2.45 с.
osm_poi_ekb_refresh укладывается — 0.1 с прогон; TRUNCATE 23 мс, INSERT 22 мс.
house_dedup_merge укладывается — 5.2 с прогон (большой CTE в одной транзакции, но statement'ы короткие).
deactivate_stale_* (6 шт.) укладываютсяUPDATE listings max 177 мс, прогон ≤ 0.6 с.
asking_to_sold_ratio_refresh, deal_city_price_bands_refresh, landing_stats_refresh, deals_freshness_monitor, sber_freshness_monitor, sber_index_pull, rosreestr_quarter_poll, house_coords_from_listings, geoportal_coords_backfill укладываются — прогон ≤ 2.7 с каждый.
domrf_kapremont_load укладывается — 8.8 с прогон, апсерт чанками.
purge_expired_trade_in_data укладывается — DELETE батчами по 500 строк, свой commit на батч.
CLI-загрузчики: gar_flats_load, zhkh_flats_load, frt_mkd_load, fns_opendata_load, dtp_stat_refresh, msk_raw_import, ekb_geoportal_ingest укладываются — все пишут чанками (500/2000 строк), statement_timeout действует на statement внутри чанка. Отдельно замерен единственный крупный set-based statement — матч ГАР→houses (gar_flats_loader._MATCH_SQL, 919 341 строка → 10 854 канона): 2.07 с с городским фильтром, 6.46 с без него. Самый длинный statement через движок из известных; запас до потолка ~3×.

Своего SET LOCAL не потребовалось никому.

Второй движок — app/core/auth_db.py (находка ревью, HIGH)

Он тоже строил коннекты без потолка, и мой первый вердикт «на проде реестр не сконфигурирован» был ложным (я прочитал устаревший докстринг как факт о текущем проде). Сверено printenv в контейнерах 12.09: IDENTITY_STORE=auth и AUTH_DB_PASSWORD задан во всех трёх сервисах образа; в БД auth 14 пользователей и живые сессии.

Путь горячий: core/rbac.py резолвит session-cookie в middleware, синхронно прямо на event loop'е, на каждом запросе с cookie. Без потолка ACCESS EXCLUSIVE на auth.sessions (миграция data/sql/auth/00*.sql или VACUUM FULL) вешал бы не четыре слота /estimate, а весь uvicorn-воркер (он один, без --workers) — включая /health.

Потолок отдан той же константой DB_CONNECT_ARGS: одна на оба движка, а не защита на одном и мина на втором. Срабатывание безопасно — вызов уже под except Exception с фолбэком на заголовочную аутентификацию, то есть отмена даёт тот же путь, что и любой другой сбой реестра, а не 500.

Класс, которого не было в таблице (находка ревью)

lock_timeout действует и на строчные блокировки, поэтому массовые UPDATE в одно окно со свипами (listing_source_snapshot 01-02, house_dedup_merge 04-05, deactivate_stale_* 06-08) могут отвалиться LockNotAvailable через 5 с. Риск низкий, отказ громкий и попадает под критерий приёмки №2 — но в первую ночь смотреть именно за этим. Мержить не перед ночным окном сбора.

Тесты по значению — tradein-mvp/backend/tests/test_3463_db_timeouts.py

Без БД (идут на обоих лэйнах):

  1. потолки реально доехали до параметров подключения прод-движка (читается cparams замыкания pool._creator, а не константа — иначе тест пережил бы снятие connect_args; наружу отдаётся только options, в cparams пароль). Сравнение на равенство, а не через in: подстрочная проверка пропускала испорченный хвост (…=30000zz содержит …=30000), а Postgres на такое отвечает FATAL: invalid value for parameter — ни одного коннекта ни в одном из трёх сервисов, полный отказ продукта;
  2. statement_timeout строго между полом (самый длинный объявленный бюджет /estimate) и крышей (<= 2 × от него), lock_timeout < statement_timeout.

Против живой Postgres (в ci-tradein.yml идут по-настоящему, на машине без БД пропускаются — записаны в tests/skip_allowlist.txt). Пропуск теперь отделён от отказа: _live_engine сначала пробивает коннект БЕЗ connect_args — сервера нет это пропуск, а «сервер есть, наши options он не принял» это падение, а не skip:

  1. живая сессия прод-движка сообщает statement_timeout = 30s и lock_timeout = 5s;
  2. SELECT pg_sleep(…) длиннее потолка обрывается QueryCanceled за отведённое время, а не висит;
  3. сценарий #3463: под ACCESS EXCLUSIVE читатель отваливается LockNotAvailable по lock_timeout, а не ждёт вечно;
  4. задача со своим SET LOCAL statement_timeout не обрезается сессионным потолком (запрос длиннее сессионного потолка доходит до конца);
  5. обратная сторона: чужой SET LOCAL не течёт за свою транзакцию — коннект не возвращается в пул без потолка.

Мутации (все красные, git stash не использовался)

мутация живая БД мок-лэйн кто ловит
connect_args=DB_CONNECT_ARGS снят 2 failed, 5 passed 1 failed, 1 passed, 5 skipped статический + живой
options испорчен (statement_timeout=30000zz) 2 failed, 5 passed 1 failed, 1 passed, 5 skipped статический (равенство) + живой (падение, не skip)
_STATEMENT_TIMEOUT_MS = 300_000 (пять минут) 2 failed, 5 passed 1 failed, 1 passed, 5 skipped согласованность (крыша) + живой

До правок по ревью вторая мутация давала 6 passed, 1 skipped — зелёный прогон при полном отказе продукта. Теперь:

E  psycopg.OperationalError: connection failed: connection to server at "127.0.0.1", port 5433 failed:
   FATAL:  invalid value for parameter "statement_timeout": "30000zz"
1 failed in 1.03s

Снятый connect_args:

E  AssertionError: движок открывает коннекты с options='', ожидалось
   '-c statement_timeout=30000 -c lock_timeout=5000': либо потолка нет вовсе …
E  AssertionError: сессия сообщает statement_timeout='0' — ожидалось 30s

Вернул → 7 passed.

Прогоны

  • tests/test_3463_db_timeouts.py против живой Postgres — 7 passed, 5.17s;
  • test_3463_db_timeouts.py + test_auth_dsn_from_parts.py + test_identity_store.py против живой БД (второй движок) — 56 passed;
  • весь сьют, мок-лэйн (DATABASE_URL=postgresql+psycopg://test:test@localhost:5432/test, как в deploy-tradein.yml) — 6046 passed, 40 skipped, PYTEST_RC=0;
  • ruff check app testsAll checks passed! (rc 0); ruff format --check по изменённым файлам — 3 files already formatted (rc 0).

Приёмка после включения

Первый критерий из issue («ноль запросов дольше потолка в pg_stat_activity для state='active'») заменён — он тавтологичен: после включения statement_timeout = 30000 активного запроса длиннее 30 с существовать не может, сервер его убивает. Зелено по построению, и «работает» от «работает слишком жёстко» не отличает. Плюс на проде log_min_duration_statement = -1 и log_lock_waits = off, так что следа отменённых в логах Postgres не останется.

За сутки после деплоя:

  1. Ноль QueryCanceled / LockNotAvailable в логах tradein-backend и tradein-scraper — по ВСЕМ путям, включая те, что в таблице вердиктов выше. Ошибка на «ожидаемом» пути означала бы ровно то, что потолок стал биндящим, и обязана вызывать откат наравне с неожиданной.
  2. Ноль новых zombie / failed в scrape_runs против предыдущих суток.

Триггер отката: срабатывание любого из двух критериев. Мержить не перед ночным окном сбора; в первую ночь отдельно смотреть за LockNotAvailable на массовых UPDATE (см. «класс, которого не было в таблице»).

Что осталось за рамками (честно)

  • refresh_search_matview — своё сырое psycopg-соединение мимо движка, 30.85 с замерены и потолка у него по-прежнему нет. Это отдельный класс (как и сказано в комментарии #3194 про «сырые psycopg-подключения мимо движков»), в #3463 не входит.
  • Поведение под реальной нагрузкой прода на новых величинах не проверено — проверяется приёмкой выше.
  • Числа ГАР-матча (2.07 / 6.46 с) и вытеснения в pg_stat_statements взяты из deep-ревью: сам я замерил только read-сторону матча (859 мс), а UPDATE на проде не гонял — это запись.
Closes #3463 У движка `app/core/db.py` не было `connect_args` вовсе, а на боевой БД `statement_timeout`, `lock_timeout` и `idle_in_transaction_session_timeout` = 0 (сверено 12.09). После #3444/#3449 шаги БД на пути `/estimate` идут через обёртку, которая при отмене по бюджету **дожидается своего потока** — ожидание верное (иначе поток остаётся сиротой в общей `Session`), но его верхняя граница равна длительности самого запроса, а у запроса границы не было. Один `ACCESS EXCLUSIVE` на таблице → четыре повисших запроса → `_ESTIMATE_CONCURRENCY = 4` исчерпан → `/estimate` отдаёт 429 всем остальным. Потолок стоит **на коннекте** (libpq `options`), а не в обёртке: таймаут в обёртке вернул бы ровно ту сироту, ради которой писался #3449. ```python connect_args={"options": "-c statement_timeout=30000 -c lock_timeout=5000"} ``` ## Откуда величины | | значение | на чём основано | |---|---|---| | `statement_timeout` | 30 000 мс | 1.5× от самого длинного **объявленного** бюджета `/estimate` (20 с — `estimate_avito_imv_timeout_s`; дальше 12 с геокод, 8 с Yandex/Cian/house_meta). ~3× от самого длинного **замеренного** set-based statement'а через движок (матч ГАР→houses, 6.46 с). Выше самой долгой чисто-БД задачи планировщика (9.7 с целиком). Сверху ограничен тестом: `<= 2 ×` объявленного бюджета. | | `lock_timeout` | 5 000 мс | Та же величина, что у миграций проекта (`SET LOCAL lock_timeout = '5s'` в `data/sql/250,251,260,272,277…`), снизу ограничена `deadlock_timeout` = 1 с на проде. Именно этот потолок закрывает сценарий #3463: под `ACCESS EXCLUSIVE` запрос **ждёт лок**, а не считает. | | `idle_in_transaction_session_timeout` | **не ставим** | Тем же движком живёт **tgbot**: `services/tgbot/bridge.py` держит транзакцию открытой поверх long-poll Telegram (замер 12.09, 3 пробы с шагом 7 с — одна и та же сессия, `SELECT value FROM tg_support_state …`, возраст транзакции циклически растёт до ~29 с). Сессионный потолок на простой ронял бы long-poll **каждый цикл**, гарантированно. | ### Замер на боевой БД (только SELECT, до правки) Основная опора — **`scrape_runs`** (длительности целых прогонов; вытеснению не подвержены): самая долгая чисто-БД задача за 14 суток — `listing_source_snapshot`, **9.7 с целиком**, весь остальной чисто-БД планировщик ≤ 8.8 с. Самый длинный **set-based statement через движок** замерен отдельно — матч ГАР→houses (`services/gar_flats_loader._MATCH_SQL`, 919 341 строка `gar_house_flats` → 10 854 канона): **2.07 с** с городским фильтром и **6.46 с** без него (`city_filter=None`, доступен флагом CLI). Это CLI-задача, в `scrape_runs` её нет. Запас до потолка ~3×, и это **считающий** запрос, а не ждущий блокировку. `pg_stat_statements` **опорой по планировщику не является** (правка после ревью): при `max = 5000` он вытесняет редкие записи — проверено вживую 12.09, `dealloc` вырос 1020→1021 за десять минут, и из топа пропали **все** записи с `calls = 1`, включая `REFRESH MATERIALIZED VIEW CONCURRENTLY` (30.85 с) и KNN `cadastral_geo_match` (2.45 с). Суточная задача до следующих суток там не доживает. Поэтому «самый долгий запрос через движок 4.27 с» верно **только для высокочастотных** запросов — это и всё, за что этот источник отвечает: * запросов длиннее 20 с — 1, длиннее 5 с — 2, и оба идут мимо движка (`REFRESH MATERIALIZED VIEW CONCURRENTLY` 30.85 с — сырое `psycopg.connect()`; `COPY _stg` 19.67 с — `psql` из ручного `scripts/local-avito-msk/collect.py`); * максимум среди высокочастотных через движок — 4.27 с (`WITH wd AS (… deals …)`, 401 вызов). ## Задачи планировщика — по каждой вердикт Движок один и тот же: `scheduler_main.py` → `RealSessionFactory` → `app.core.db.SessionLocal`. **Потолок накрывает и продуктовый путь, и планировщик**, и все три сервиса образа (backend / scraper / tgbot). | задача / путь | вердикт | |---|---| | `listing_source_snapshot` | **свой `SET LOCAL`** — `statement_timeout = 900000` (`tasks/listing_source_snapshot.py:288`). Перекрытие сессионного потолка ПРОВЕРЕНО тестом, а не предположено. Сверх того укладывается: 9.7 с на прогон. | | `proxy_pool.attribute_run_proxy` | **свой `SET LOCAL`** — `lock_timeout = '2s'` (`services/proxy_pool.py:513`), строже нового потолка. | | `refresh_search_matview` | **мимо движка** — `psycopg.connect(dsn, autocommit=True)`. 30.85 с замерены, `connect_args` его не касается. | | миграции `data/sql/*.sql` | **мимо движка** — `psql` из `deploy-tradein.yml`, у DDL свой `SET LOCAL lock_timeout = '5s'`. | | свипы avito/cian/yandex/domclick, `*_detail_backfill`, `geocode_missing_listings`, `proxy_healthcheck`, `newbuilding_enrich`, `house_imv_backfill` | **укладываются** — прогон идёт часами, но это питон-циклы коротких statement'ов + HTTP; `statement_timeout` действует НА STATEMENT, а не на транзакцию. Единственное, что их убило бы, — `idle_in_transaction_session_timeout`, и его мы не ставим. | | `rosreestr_dkp_import` / `_77` | **укладывается** — FDW читается страницами по 2000 (`batch_size`), 428 statement'ов, max 629 мс; прогон 102 с целиком. | | `cadastral_geo_match` | **укладывается** — 4.2 с прогон; `TRUNCATE cad_buildings_local` 23 мс, `INSERT … FROM` FDW 748 мс, KNN-матч 2.45 с. | | `osm_poi_ekb_refresh` | **укладывается** — 0.1 с прогон; `TRUNCATE` 23 мс, `INSERT` 22 мс. | | `house_dedup_merge` | **укладывается** — 5.2 с прогон (большой CTE в одной транзакции, но statement'ы короткие). | | `deactivate_stale_*` (6 шт.) | **укладываются** — `UPDATE listings` max 177 мс, прогон ≤ 0.6 с. | | `asking_to_sold_ratio_refresh`, `deal_city_price_bands_refresh`, `landing_stats_refresh`, `deals_freshness_monitor`, `sber_freshness_monitor`, `sber_index_pull`, `rosreestr_quarter_poll`, `house_coords_from_listings`, `geoportal_coords_backfill` | **укладываются** — прогон ≤ 2.7 с каждый. | | `domrf_kapremont_load` | **укладывается** — 8.8 с прогон, апсерт чанками. | | `purge_expired_trade_in_data` | **укладывается** — DELETE батчами по 500 строк, свой commit на батч. | | CLI-загрузчики: `gar_flats_load`, `zhkh_flats_load`, `frt_mkd_load`, `fns_opendata_load`, `dtp_stat_refresh`, `msk_raw_import`, `ekb_geoportal_ingest` | **укладываются** — все пишут чанками (500/2000 строк), `statement_timeout` действует на statement внутри чанка. Отдельно замерен единственный крупный set-based statement — матч ГАР→houses (`gar_flats_loader._MATCH_SQL`, 919 341 строка → 10 854 канона): **2.07 с** с городским фильтром, **6.46 с** без него. Самый длинный statement через движок из известных; запас до потолка ~3×. | Своего `SET LOCAL` не потребовалось никому. ### Второй движок — `app/core/auth_db.py` (находка ревью, HIGH) Он тоже строил коннекты без потолка, и мой первый вердикт «на проде реестр не сконфигурирован» был **ложным** (я прочитал устаревший докстринг как факт о текущем проде). Сверено `printenv` в контейнерах 12.09: `IDENTITY_STORE=auth` и `AUTH_DB_PASSWORD` задан во **всех трёх** сервисах образа; в БД `auth` 14 пользователей и живые сессии. Путь горячий: `core/rbac.py` резолвит session-cookie в **middleware**, синхронно прямо на event loop'е, на каждом запросе с cookie. Без потолка `ACCESS EXCLUSIVE` на `auth.sessions` (миграция `data/sql/auth/00*.sql` или `VACUUM FULL`) вешал бы не четыре слота `/estimate`, а **весь uvicorn-воркер** (он один, без `--workers`) — включая `/health`. Потолок отдан той же константой `DB_CONNECT_ARGS`: одна на оба движка, а не защита на одном и мина на втором. Срабатывание безопасно — вызов уже под `except Exception` с фолбэком на заголовочную аутентификацию, то есть отмена даёт тот же путь, что и любой другой сбой реестра, а не 500. ### Класс, которого не было в таблице (находка ревью) `lock_timeout` действует и на **строчные** блокировки, поэтому массовые UPDATE в одно окно со свипами (`listing_source_snapshot` 01-02, `house_dedup_merge` 04-05, `deactivate_stale_*` 06-08) могут отвалиться `LockNotAvailable` через 5 с. Риск низкий, отказ громкий и попадает под критерий приёмки №2 — но **в первую ночь смотреть именно за этим**. Мержить **не перед ночным окном сбора**. ## Тесты по значению — `tradein-mvp/backend/tests/test_3463_db_timeouts.py` Без БД (идут на обоих лэйнах): 1. потолки реально доехали до параметров подключения **прод-движка** (читается `cparams` замыкания `pool._creator`, а не константа — иначе тест пережил бы снятие `connect_args`; наружу отдаётся только `options`, в `cparams` пароль). Сравнение на **равенство**, а не через `in`: подстрочная проверка пропускала испорченный хвост (`…=30000zz` содержит `…=30000`), а Postgres на такое отвечает `FATAL: invalid value for parameter` — ни одного коннекта ни в одном из трёх сервисов, полный отказ продукта; 2. `statement_timeout` строго между полом (самый длинный объявленный бюджет `/estimate`) и **крышей** (`<= 2 ×` от него), `lock_timeout` < `statement_timeout`. Против живой Postgres (в `ci-tradein.yml` идут по-настоящему, на машине без БД пропускаются — записаны в `tests/skip_allowlist.txt`). Пропуск теперь **отделён от отказа**: `_live_engine` сначала пробивает коннект БЕЗ `connect_args` — сервера нет это пропуск, а «сервер есть, наши `options` он не принял» это падение, а не `skip`: 3. живая сессия **прод-движка** сообщает `statement_timeout = 30s` и `lock_timeout = 5s`; 4. `SELECT pg_sleep(…)` длиннее потолка **обрывается** `QueryCanceled` за отведённое время, а не висит; 5. **сценарий #3463**: под `ACCESS EXCLUSIVE` читатель отваливается `LockNotAvailable` по `lock_timeout`, а не ждёт вечно; 6. задача со своим `SET LOCAL statement_timeout` **не обрезается** сессионным потолком (запрос длиннее сессионного потолка доходит до конца); 7. обратная сторона: чужой `SET LOCAL` **не течёт** за свою транзакцию — коннект не возвращается в пул без потолка. ### Мутации (все красные, `git stash` не использовался) | мутация | живая БД | мок-лэйн | кто ловит | |---|---|---|---| | `connect_args=DB_CONNECT_ARGS` снят | 2 failed, 5 passed | 1 failed, 1 passed, 5 skipped | статический + живой | | `options` испорчен (`statement_timeout=30000zz`) | 2 failed, 5 passed | 1 failed, 1 passed, 5 skipped | статический (равенство) + живой (падение, не skip) | | `_STATEMENT_TIMEOUT_MS = 300_000` (пять минут) | 2 failed, 5 passed | 1 failed, 1 passed, 5 skipped | согласованность (крыша) + живой | До правок по ревью вторая мутация давала **6 passed, 1 skipped** — зелёный прогон при полном отказе продукта. Теперь: ``` E psycopg.OperationalError: connection failed: connection to server at "127.0.0.1", port 5433 failed: FATAL: invalid value for parameter "statement_timeout": "30000zz" 1 failed in 1.03s ``` Снятый `connect_args`: ``` E AssertionError: движок открывает коннекты с options='', ожидалось '-c statement_timeout=30000 -c lock_timeout=5000': либо потолка нет вовсе … E AssertionError: сессия сообщает statement_timeout='0' — ожидалось 30s ``` Вернул → `7 passed`. ### Прогоны * `tests/test_3463_db_timeouts.py` против живой Postgres — **7 passed, 5.17s**; * `test_3463_db_timeouts.py` + `test_auth_dsn_from_parts.py` + `test_identity_store.py` против живой БД (второй движок) — **56 passed**; * весь сьют, мок-лэйн (`DATABASE_URL=postgresql+psycopg://test:test@localhost:5432/test`, как в `deploy-tradein.yml`) — **6046 passed, 40 skipped**, `PYTEST_RC=0`; * `ruff check app tests` — `All checks passed!` (rc 0); `ruff format --check` по изменённым файлам — `3 files already formatted` (rc 0). ## Приёмка после включения Первый критерий из issue (**«ноль запросов дольше потолка в `pg_stat_activity` для `state='active'`»**) заменён — он **тавтологичен**: после включения `statement_timeout = 30000` активного запроса длиннее 30 с существовать не может, сервер его убивает. Зелено по построению, и «работает» от «работает слишком жёстко» не отличает. Плюс на проде `log_min_duration_statement = -1` и `log_lock_waits = off`, так что следа отменённых в логах Postgres не останется. За сутки после деплоя: 1. **Ноль `QueryCanceled` / `LockNotAvailable` в логах `tradein-backend` и `tradein-scraper` — по ВСЕМ путям, включая те, что в таблице вердиктов выше.** Ошибка на «ожидаемом» пути означала бы ровно то, что потолок стал биндящим, и обязана вызывать откат наравне с неожиданной. 2. **Ноль новых `zombie` / `failed` в `scrape_runs` против предыдущих суток.** **Триггер отката:** срабатывание любого из двух критериев. Мержить не перед ночным окном сбора; в первую ночь отдельно смотреть за `LockNotAvailable` на массовых UPDATE (см. «класс, которого не было в таблице»). ## Что осталось за рамками (честно) * **`refresh_search_matview`** — своё сырое psycopg-соединение мимо движка, 30.85 с замерены и потолка у него по-прежнему нет. Это отдельный класс (как и сказано в комментарии #3194 про «сырые psycopg-подключения мимо движков»), в #3463 не входит. * Поведение под реальной нагрузкой прода на новых величинах не проверено — проверяется приёмкой выше. * Числа ГАР-матча (2.07 / 6.46 с) и вытеснения в `pg_stat_statements` взяты из deep-ревью: сам я замерил только read-сторону матча (859 мс), а `UPDATE` на проде не гонял — это запись.
bot-backend added 1 commit 2026-09-12 14:48:52 +00:00
tradein: потолок на запрос и на ожидание блокировки для движка БД (#3463)
All checks were successful
CI Trade-In / backend-tests (pull_request) Successful in 5m9s
CI Trade-In / changes (pull_request) Successful in 9s
CI Trade-In / browser-tests (pull_request) Has been skipped
CI Trade-In / frontend-checks (pull_request) Has been skipped
CI / changes (pull_request) Successful in 12s
CI / backend-tests (pull_request) Has been skipped
CI / frontend-tests (pull_request) Has been skipped
CI / openapi-codegen-check (pull_request) Has been skipped
a8503d3a58
На боевой БД `statement_timeout`, `lock_timeout` и
`idle_in_transaction_session_timeout` равны 0, а у движка `app/core/db.py` не
было `connect_args` вовсе. После #3444/#3449 шаги БД на пути `/estimate` идут
через обёртку, которая при отмене по бюджету ДОЖИДАЕТСЯ своего потока (иначе он
остаётся сиротой в общей `Session`) — ожидание верное, но его верхняя граница
равна длительности самого запроса, а у запроса границы не было. Один
`ACCESS EXCLUSIVE` на таблице → четыре повисших запроса → `_ESTIMATE_CONCURRENCY`
исчерпан → `/estimate` отдаёт 429 всем остальным.

Потолок ставится на КОННЕКТЕ (libpq `options`), а не в обёртке: таймаут в
обёртке вернул бы ровно ту сироту, ради которой писался #3449.

statement_timeout = 30 с: выше самого длинного ОБЪЯВЛЕННОГО бюджета `/estimate`
(20 с, `estimate_avito_imv_timeout_s`) в 1.5 раза и в 7 раз выше самого долгого
ЗАМЕРЕННОГО запроса через этот движок (4.27 с, `pg_stat_statements` на проде за
16 суток), но конечен. lock_timeout = 5 с: та же величина, что у миграций
проекта, и больше `deadlock_timeout` (1 с на проде).

`idle_in_transaction_session_timeout` намеренно не трогаем: тем же движком живёт
планировщик, а его свипы держат транзакцию открытой всё время внешнего HTTP
(замер: живая сессия `idle in transaction` 29 с).

Задачи планировщика проверены, а не предположены: у `listing_source_snapshot`
свой `SET LOCAL statement_timeout = 900000`, и тест доказывает, что `SET LOCAL`
ПЕРЕКРЫВАЕТ сессионный потолок и не течёт за свою транзакцию. Самая долгая
чисто-БД задача по `scrape_runs` за 14 суток укладывается в 9.7 с целиком;
единственный запрос длиннее 20 с на всей БД (`REFRESH MATERIALIZED VIEW
CONCURRENTLY`, 30.85 с) идёт мимо движка — по своему сырому psycopg-соединению.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Light1YT added 1 commit 2026-09-12 15:36:06 +00:00
tradein: тот же потолок второму движку + тесты, которые ловят испорченное значение (#3463)
All checks were successful
CI Trade-In / changes (pull_request) Successful in 8s
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 Trade-In / backend-tests (pull_request) Successful in 4m45s
CI / changes (pull_request) Successful in 11s
CI / frontend-tests (pull_request) Has been skipped
CI / openapi-codegen-check (pull_request) Has been skipped
70bb5a3a8f
Правки по deep-ревью PR #3508.

1. HIGH. `app/core/auth_db.py` строил второй движок БЕЗ `connect_args`, а моё
обоснование пропуска было ложным: на проде `IDENTITY_STORE=auth` во всех трёх
сервисах образа и `AUTH_DB_PASSWORD` задан (сверено `printenv` в контейнерах),
то есть реестр живой. Путь горячий: `core/rbac.py` резолвит session-cookie в
middleware, синхронно на event loop'е, на каждом запросе с cookie — значит
`ACCESS EXCLUSIVE` на `auth.sessions` вешал бы не четыре слота `/estimate`, а
весь uvicorn-воркер (он один), включая `/health`. Потолок — та же константа
`DB_CONNECT_ARGS`: одна на оба движка, а не защита на одном и мина на втором.
Срабатывание безопасно — вызов уже под `except Exception` с фолбэком.

2. MEDIUM. Испорченный `options` (`statement_timeout=30000zz`) проходил ЗЕЛЁНЫМ:
статическая проверка искала ПОДСТРОКУ (а `…=30000` — префикс испорченного), а
живая глушила отказ коннекта голым `except` → skip → запись в allowlist. На
проде это `FATAL: invalid value for parameter` на КАЖДОМ коннекте, то есть
полный отказ продукта при зелёном сьюте. Теперь: сравнение `options` на
РАВЕНСТВО, и `_live_engine` сначала пробует коннект БЕЗ `connect_args` — сервера
нет это пропуск, а «сервер есть, наши options он не принял» это падение.

3. LOW. У проверки согласованности был пол и не было крыши: `300_000` (пять
минут) зеленел. Добавлена симметричная граница `<= 2 ×` самого длинного
объявленного бюджета.

4. LOW. Три факта в комментариях исправлены:
   * `pg_stat_statements` НЕ опора по планировщику — вытесняет записи с calls=1
     (`dealloc` вырос за десять минут, из топа пропал `REFRESH MATERIALIZED VIEW`
     30.85 с). Основная опора — `scrape_runs`;
   * самый длинный set-based statement через движок — матч ГАР→houses: 2.07 с с
     городским фильтром и 6.46 с без. Запас ~3×, а не 7×;
   * `idle in transaction` 29 с — это tgbot (`services/tgbot/bridge.py`,
     транзакция поверх long-poll Telegram; сверено 3 пробами: одна и та же
     сессия, `SELECT value FROM tg_support_state …`), а не свипы. Решение не
     ставить потолок на простой от этого только крепче.

Мутационная проверка (обе лэйны краснеют на каждой): испорченный `options`,
`_STATEMENT_TIMEOUT_MS = 300_000`, снятый `connect_args`.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Author
Collaborator

Ответ на deep-ревью — всё принято, правки в 70bb5a3a.

находка что сделано
HIGH второй движок без потолка, обоснование пропуска ложно Проверил сам: IDENTITY_STORE=auth + AUTH_DB_PASSWORD во всех трёх контейнерах. connect_args=DB_CONNECT_ARGS в auth_db.py — одна константа на оба движка. Ложное утверждение из «за рамками» убрано.
MEDIUM испорченный options зеленеет Равенство вместо in; _live_engine пробивает коннект без connect_args и отличает «сервера нет» (skip) от «сервер не принял наши options» (fail). Мутация теперь даёт FATAL: invalid value for parameter "statement_timeout": "30000zz", а не skip.
MEDIUM тавтологичный критерий приёмки Заменён на счёт QueryCanceled/LockNotAvailable в логах backend+scraper по всем путям, включая таблицу вердиктов. Триггер отката переписан.
LOW нет крыши у согласованности <= 2 × объявленного бюджета; мутация 300_000 краснеет на обеих лэйнах.
LOW три неверных факта Исправлены в db.py и в теле PR: область замера (pg_stat_statements вытесняет calls=1 → опора scrape_runs), ГАР-матч 2.07/6.46 с вместо 859 мс read-стороны, idle in transaction = tgbot long-poll (подтвердил тремя пробами: один pid, tg_support_state), а не свипы.
строчные блокировки Дописан в PR как отдельный класс + «мержить не перед ночным окном сбора».

Мутационная таблица (все три красные на обеих лэйнах) и числа прогонов — в теле PR.

Ответ на deep-ревью — всё принято, правки в `70bb5a3a`. | находка | что сделано | |---|---| | **HIGH** второй движок без потолка, обоснование пропуска ложно | Проверил сам: `IDENTITY_STORE=auth` + `AUTH_DB_PASSWORD` во всех трёх контейнерах. `connect_args=DB_CONNECT_ARGS` в `auth_db.py` — одна константа на оба движка. Ложное утверждение из «за рамками» убрано. | | **MEDIUM** испорченный `options` зеленеет | Равенство вместо `in`; `_live_engine` пробивает коннект без `connect_args` и отличает «сервера нет» (skip) от «сервер не принял наши options» (fail). Мутация теперь даёт `FATAL: invalid value for parameter "statement_timeout": "30000zz"`, а не `skip`. | | **MEDIUM** тавтологичный критерий приёмки | Заменён на счёт `QueryCanceled`/`LockNotAvailable` в логах backend+scraper **по всем путям, включая таблицу вердиктов**. Триггер отката переписан. | | **LOW** нет крыши у согласованности | `<= 2 ×` объявленного бюджета; мутация `300_000` краснеет на обеих лэйнах. | | **LOW** три неверных факта | Исправлены в `db.py` и в теле PR: область замера (`pg_stat_statements` вытесняет `calls=1` → опора `scrape_runs`), ГАР-матч 2.07/6.46 с вместо 859 мс read-стороны, `idle in transaction` = tgbot long-poll (подтвердил тремя пробами: один pid, `tg_support_state`), а не свипы. | | строчные блокировки | Дописан в PR как отдельный класс + «мержить не перед ночным окном сбора». | Мутационная таблица (все три красные на обеих лэйнах) и числа прогонов — в теле PR.
bot-backend merged commit 6ba04d845e into main 2026-09-12 16:38:35 +00:00
Sign in to join this conversation.
No reviewers
No milestone
No project
No assignees
2 participants
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: lekss361/gendesign#3508
No description provided.