lekss361/gendesign

Fork 0

tradein-backend: у запросов к БД нет потолка ни по времени, ни по ожиданию блокировки — одна заблокированная таблица вешает /estimate для всех #3463

New issue

Closed

opened 2026-09-12 08:58:17 +00:00 by bot-backend · 1 comment

bot-backend commented

2026-09-12 08:58:17 +00:00

Collaborator

Найдено при deep-ревью PR #3460 (#3449). Уже на main, PR #3460 этого не вносит и не чинит.

Факт

На боевой БД (SELECT name, setting FROM pg_settings, 2026-09-12):

statement_timeout                   | 0
lock_timeout                        | 0
idle_in_transaction_session_timeout | 0

connect_args у движка (app/core/db.py) не задан вовсе — грепом по app/ единственные потолки это SET LOCAL внутри отдельных задач планировщика (listing_source_snapshot.py:288, proxy_pool.py:513). Ручки продукта не покрыты ничем.

Это ровно п.2 закрытого #2607 («server/role-level statement_timeout — отдельное решение»), который так и не был принят.

Почему это стало важно сейчас

После #3444 и #3460 все шаги БД на пути /estimate идут через обёртку, которая при отмене по бюджету ждёт завершения потока (asyncio.wait([step]) без timeout) — иначе поток остаётся сиротой в сессии запроса и следующий шаг ловит «another operation is in progress». Ожидание корректное, но его верхняя граница = время самого запроса к БД, а у запроса границы нет.

Сценарий отказа (вход → результат)

На geocode_cache берётся ACCESS EXCLUSIVE — миграция, VACUUM FULL или зависший ALTER.
POST /estimate → _with_budget(geocode(...), 12 с) → шаг БД блокируется на блокировке.
Бюджет истекает, обёртка уходит ждать поток — без потолка.
Запрос не завершается никогда. Слот _estimate_slots не возвращается (trade_in.py:94, релиз в finally, до которого не доходит).
_ESTIMATE_CONCURRENCY = 4 → четыре таких запроса, и /estimate отдаёт 429 всем остальным (_ESTIMATE_SLOT_WAIT_S = 5.0) до снятия блокировки. Клиент видит 504 от Caddy, бэкенд считает запрос живым.

Тот же класс закрывает и синхронные пути, у которых обёртки нет вовсе (house_metadata.py:244 ходит в БД прямо на loop'е).

Как чинить

Потолок ставится на движке, а не в обёртке (таймаут в обёртке вернул бы сироту — то, ради чего #3449 и писался):

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

Величины подобрать по фактическим бюджетам: самый длинный объявленный бюджет на /estimate — 20 с (IMV), геокод 12 с, остальные 8 с. lock_timeout заведомо меньше — ждать блокировку дольше секунд смысла нет, лучше деградировать.

Осторожно с задачами планировщика: у них есть заведомо длинные транзакции (listing_source_snapshot — SET LOCAL statement_timeout = 900000). SET LOCAL перекрывает сессионное значение, так что они не пострадают, но это надо ПРОВЕРИТЬ, а не предположить: пройти по всем задачам, у которых транзакция может быть длиннее 20 с, и убедиться, что у каждой либо свой SET LOCAL, либо она укладывается.

Тест по значению

Запрос, который заведомо превышает потолок (SELECT pg_sleep(...)), обязан упасть с QueryCanceled за отведённое время, а не висеть; и параллельно — задача со своим SET LOCAL не должна обрываться новым сессионным потолком. Фальсификация: снять connect_args → первый тест краснеет.

Приёмка

За сутки после включения: ноль запросов к tradein дольше statement_timeout в pg_stat_activity (замер по max(now() - query_start) для state='active'), и ноль новых zombie/failed в scrape_runs по сравнению с предыдущими сутками.

Refs #3449, PR #3460, #2607 (п.2), #3408.

Найдено при deep-ревью PR #3460 (#3449). **Уже на `main`**, PR #3460 этого не вносит и не чинит. ## Факт На боевой БД (`SELECT name, setting FROM pg_settings`, 2026-09-12): ``` statement_timeout | 0 lock_timeout | 0 idle_in_transaction_session_timeout | 0 ``` `connect_args` у движка (`app/core/db.py`) не задан вовсе — грепом по `app/` единственные потолки это `SET LOCAL` внутри отдельных задач планировщика (`listing_source_snapshot.py:288`, `proxy_pool.py:513`). Ручки продукта не покрыты ничем. Это ровно п.2 закрытого #2607 («server/role-level statement_timeout — отдельное решение»), который так и не был принят. ## Почему это стало важно сейчас После #3444 и #3460 все шаги БД на пути `/estimate` идут через обёртку, которая при отмене по бюджету **ждёт завершения потока** (`asyncio.wait([step])` без `timeout`) — иначе поток остаётся сиротой в сессии запроса и следующий шаг ловит «another operation is in progress». Ожидание корректное, но его верхняя граница = время самого запроса к БД, а у запроса границы нет. ## Сценарий отказа (вход → результат) 1. На `geocode_cache` берётся `ACCESS EXCLUSIVE` — миграция, `VACUUM FULL` или зависший `ALTER`. 2. `POST /estimate` → `_with_budget(geocode(...), 12 с)` → шаг БД блокируется на блокировке. 3. Бюджет истекает, обёртка уходит ждать поток — **без потолка**. 4. Запрос не завершается никогда. Слот `_estimate_slots` не возвращается (`trade_in.py:94`, релиз в `finally`, до которого не доходит). 5. `_ESTIMATE_CONCURRENCY = 4` → четыре таких запроса, и `/estimate` отдаёт **429 всем остальным** (`_ESTIMATE_SLOT_WAIT_S = 5.0`) до снятия блокировки. Клиент видит 504 от Caddy, бэкенд считает запрос живым. Тот же класс закрывает и синхронные пути, у которых обёртки нет вовсе (`house_metadata.py:244` ходит в БД прямо на loop'е). ## Как чинить Потолок ставится на движке, а не в обёртке (таймаут в обёртке вернул бы сироту — то, ради чего #3449 и писался): ```python connect_args={"options": "-c statement_timeout=20000 -c lock_timeout=5000"} ``` Величины подобрать по фактическим бюджетам: самый длинный объявленный бюджет на `/estimate` — 20 с (IMV), геокод 12 с, остальные 8 с. `lock_timeout` заведомо меньше — ждать блокировку дольше секунд смысла нет, лучше деградировать. **Осторожно с задачами планировщика:** у них есть заведомо длинные транзакции (`listing_source_snapshot` — `SET LOCAL statement_timeout = 900000`). `SET LOCAL` перекрывает сессионное значение, так что они не пострадают, но это надо ПРОВЕРИТЬ, а не предположить: пройти по всем задачам, у которых транзакция может быть длиннее 20 с, и убедиться, что у каждой либо свой `SET LOCAL`, либо она укладывается. ## Тест по значению Запрос, который заведомо превышает потолок (`SELECT pg_sleep(...)`), обязан упасть с `QueryCanceled` за отведённое время, а не висеть; и параллельно — задача со своим `SET LOCAL` не должна обрываться новым сессионным потолком. Фальсификация: снять `connect_args` → первый тест краснеет. ## Приёмка За сутки после включения: ноль запросов к `tradein` дольше `statement_timeout` в `pg_stat_activity` (замер по `max(now() - query_start)` для `state='active'`), и ноль новых `zombie`/`failed` в `scrape_runs` по сравнению с предыдущими сутками. Refs #3449, PR #3460, #2607 (п.2), #3408.

bot-backend referenced this issue

2026-09-12 10:21:48 +00:00

geocoder: отмена по бюджету оставляет поток работать с сессией запроса — следующий шаг ловит «another operation is in progress», персист оценки отдаёт 500 #3449

bot-backend referenced this issue

2026-09-12 11:01:11 +00:00

tradein: транзакция живёт дольше часа регулярно (50 замеров из 4033 за 14 суток, пик 2.2 ч) — пока она жива, vacuum не убирает мёртвые строки во ВСЕЙ базе #3480

Light1YT referenced this issue from a commit

2026-09-12 14:47:08 +00:00

tradein: потолок на запрос и на ожидание блокировки для движка БД (#3463)

bot-backend referenced this issue from a pull request that will close it,

2026-09-12 14:48:51 +00:00

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

bot-backend referenced this issue

2026-09-12 14:52:05 +00:00

bot-backend referenced this issue

2026-09-12 15:29:33 +00:00

Light1YT referenced this issue from a commit

2026-09-12 15:36:05 +00:00

tradein: тот же потолок второму движку + тесты, которые ловят испорченное значение (#3463)

bot-backend closed this issue

2026-09-12 16:38:35 +00:00

bot-backend referenced this issue from a commit

2026-09-12 16:38:35 +00:00

Merge pull request 'МЕРА: у запросов к БД появился потолок по времени и по ожиданию блокировки (#3463)' (#3508) from fix/3463-db-statement-timeout into main

bot-backend commented

2026-09-12 17:20:54 +00:00

Author

Collaborator

Приёмка на проде — 2026-09-12

PR #3508 смержен. Проверял не статусом джобы, а живым коннектом через тот же движок, которым ходит продукт:

connect_args движка: {'options': '-c statement_timeout=30000 -c lock_timeout=5000'}
statement_timeout = 30s
lock_timeout      = 5s

И отдельно второй движок (app/core/auth_db.py) — тот самый, про который в первой редакции PR стояло «на проде не сконфигурирован», а на деле IDENTITY_STORE=auth во всех трёх контейнерах и вызов висит синхронно в middleware на каждом запросе с сессионной кукой:

auth statement_timeout = 30s
auth lock_timeout      = 5s

Что проверить дальше — с датой

Приёмка из issue сегодня невыполнима: контейнер пересоздан деплоем, окно логов — минуты. Не раньше 2026-09-13 18:00 UTC (то есть после первого полного ночного окна сбора):

ssh poincare 'docker inspect tradein-backend --format "{{.State.StartedAt}}";   for C in tradein-backend tradein-scraper; do     echo "== $C"; docker logs --since 24h $C 2>&1 | wc -l;     docker logs --since 24h $C 2>&1 | grep -c -E "QueryCanceled|LockNotAvailable"; done'

Если StartedAt моложе суток — окно неполное, число недействительно.

Отдельно посмотреть глазами первые прогоны, где новый lock_timeout может дать первый честный отказ: listing_source_snapshot (01–02 UTC) и house_dedup_merge (04–05 UTC) — по scrape_runs.status.

Триггер отката (один коммит, состояние БД не меняется): рост failed/zombie в scrape_runs против предыдущих суток либо появление QueryCanceled/LockNotAvailable на путях, признанных в PR укладывающимися.

## Приёмка на проде — 2026-09-12 PR #3508 смержен. Проверял не статусом джобы, а живым коннектом через тот же движок, которым ходит продукт: ``` connect_args движка: {'options': '-c statement_timeout=30000 -c lock_timeout=5000'} statement_timeout = 30s lock_timeout = 5s ``` И отдельно второй движок (`app/core/auth_db.py`) — тот самый, про который в первой редакции PR стояло «на проде не сконфигурирован», а на деле `IDENTITY_STORE=auth` во всех трёх контейнерах и вызов висит синхронно в middleware на каждом запросе с сессионной кукой: ``` auth statement_timeout = 30s auth lock_timeout = 5s ``` ## Что проверить дальше — с датой Приёмка из issue сегодня невыполнима: контейнер пересоздан деплоем, окно логов — минуты. **Не раньше 2026-09-13 18:00 UTC** (то есть после первого полного ночного окна сбора): ```bash ssh poincare 'docker inspect tradein-backend --format "{{.State.StartedAt}}"; for C in tradein-backend tradein-scraper; do echo "== $C"; docker logs --since 24h $C 2>&1 | wc -l; docker logs --since 24h $C 2>&1 | grep -c -E "QueryCanceled|LockNotAvailable"; done' ``` Если `StartedAt` моложе суток — окно неполное, число недействительно. Отдельно посмотреть глазами первые прогоны, где новый `lock_timeout` может дать первый честный отказ: `listing_source_snapshot` (01–02 UTC) и `house_dedup_merge` (04–05 UTC) — по `scrape_runs.status`. Триггер отката (один коммит, состояние БД не меняется): рост `failed`/`zombie` в `scrape_runs` против предыдущих суток **либо** появление `QueryCanceled`/`LockNotAvailable` на путях, признанных в PR укладывающимися.