lekss361/gendesign

Fork 0

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

New issue

Closed

opened 2026-09-11 21:30:26 +00:00 by bot-backend · 1 comment

bot-backend commented

2026-09-11 21:30:26 +00:00

Collaborator

Найдено при deep-ревью PR #3444 (#3083/#3408). На main уже есть, PR #3444 эту дыру не закрывает — там она починена только для шагов, идущих через новую обёртку _db_step.

Класс дефекта. asyncio.to_thread нельзя отменить: при срабатывании _with_budget (это asyncio.wait_for, estimator.py:2948-2965) корутина умирает, а поток продолжает работать с той же Session. Дальше следующий шаг входит в ту же сессию — два потока в одной Session → InvalidRequestError / «another operation is in progress». Воспроизведено на структуре 1-в-1 с боевой:

budget expired -> caller continues
CONFLICT: next-stage entered while busy
CONCURRENT ACCESS HAPPENED: True

Где именно (все на main): app/services/geocoder.py:1912, 1958, 1983, 2007, 2018, 2037 — geocode(payload.address, db, …) обёрнут в _with_budget (12 с), а внутри делает asyncio.to_thread(_cache_get, db, …) / _cache_put по ТОЙ ЖЕ сессии запроса.

Почему это больно именно на /estimate: пострадавшим оказывается не сам геокодер (его ошибки проглатываются), а следующий потребитель сессии. В частности _persist_estimate_and_commit (estimator.py:5224) не обёрнут в try — это 500 и потерянная оценка клиента, а не деградация.

Как чинить (образец уже в репо после #3444): ждать поток в точке отмены — asyncio.ensure_future + asyncio.shield, в except asyncio.CancelledError дождаться asyncio.wait([step]), прочитать step.exception() (иначе asyncio печатает «Task exception was never retrieved») и raise. Важно: threading.Lock внутри одной обёртки здесь НЕ годится — в эстиматоре ещё ~17 мест с голым asyncio.to_thread(db…) (_fetch_anchor_comps, _fetch_price_trend, _is_premium_building, _save_yandex_history_items, _backfill_house_fias, сам персист), они лока не берут.

Тест по значению (образец — tests/test_3408_db_step_cancel_orphan.py): отмена по бюджету во время шага БД → следующий голый to_thread(db.execute, …) не входит в сессию, пока сирота не закончил; на нынешнем main тест краснеет с assert 1 == 0.

Приёмка: после фикса — ноль строк another operation is in progress / InvalidRequestError в логах tradein-backend за сутки под нагрузкой, и тест выше зелёный.

Refs #3083, #3408, PR #3444, #654.

Найдено при deep-ревью PR #3444 (#3083/#3408). **На `main` уже есть**, PR #3444 эту дыру не закрывает — там она починена только для шагов, идущих через новую обёртку `_db_step`. **Класс дефекта.** `asyncio.to_thread` **нельзя отменить**: при срабатывании `_with_budget` (это `asyncio.wait_for`, `estimator.py:2948-2965`) корутина умирает, а поток продолжает работать с той же `Session`. Дальше следующий шаг входит в ту же сессию — два потока в одной `Session` → `InvalidRequestError` / «another operation is in progress». Воспроизведено на структуре 1-в-1 с боевой: ``` budget expired -> caller continues CONFLICT: next-stage entered while busy CONCURRENT ACCESS HAPPENED: True ``` **Где именно (все на `main`):** `app/services/geocoder.py:1912, 1958, 1983, 2007, 2018, 2037` — `geocode(payload.address, db, …)` обёрнут в `_with_budget` (12 с), а внутри делает `asyncio.to_thread(_cache_get, db, …)` / `_cache_put` по ТОЙ ЖЕ сессии запроса. **Почему это больно именно на `/estimate`:** пострадавшим оказывается не сам геокодер (его ошибки проглатываются), а следующий потребитель сессии. В частности `_persist_estimate_and_commit` (`estimator.py:5224`) не обёрнут в `try` — это 500 и **потерянная оценка клиента**, а не деградация. **Как чинить (образец уже в репо после #3444):** ждать поток в точке отмены — `asyncio.ensure_future` + `asyncio.shield`, в `except asyncio.CancelledError` дождаться `asyncio.wait([step])`, прочитать `step.exception()` (иначе asyncio печатает «Task exception was never retrieved») и `raise`. Важно: `threading.Lock` внутри одной обёртки здесь НЕ годится — в эстиматоре ещё ~17 мест с голым `asyncio.to_thread(db…)` (`_fetch_anchor_comps`, `_fetch_price_trend`, `_is_premium_building`, `_save_yandex_history_items`, `_backfill_house_fias`, сам персист), они лока не берут. **Тест по значению (образец — `tests/test_3408_db_step_cancel_orphan.py`):** отмена по бюджету во время шага БД → следующий **голый** `to_thread(db.execute, …)` не входит в сессию, пока сирота не закончил; на нынешнем `main` тест краснеет с `assert 1 == 0`. **Приёмка:** после фикса — ноль строк `another operation is in progress` / `InvalidRequestError` в логах `tradein-backend` за сутки под нагрузкой, и тест выше зелёный. Refs #3083, #3408, PR #3444, #654.

bot-backend referenced this issue

2026-09-11 21:46:53 +00:00

MERA: бэкенд оценки крутится в один воркер uvicorn — тяжёлый /estimate внутри event loop блокирует всех #3083

bot-backend referenced this issue

2026-09-11 21:46:53 +00:00

tradein-backend: пул коннектов SQLAlchemy 15 против пикового спроса до 28 на /estimate; sync db.execute/commit в estimator и cian_price_history на публичном event loop #3408

Light1YT referenced this issue from a commit

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

Отмена по бюджету больше не оставляет сироту в сессии запроса (#3449)

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

2026-09-12 08:23:38 +00:00

Оценка не теряется, когда геокодер не уложился в бюджет (#3449) #3460

bot-backend referenced this issue

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

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

bot-backend closed this issue

2026-09-12 10:11:20 +00:00

bot-backend referenced this issue from a commit

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

Отмена по бюджету больше не оставляет поток в сессии запроса — оценка не теряется на 500 (#3449)

bot-backend commented

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

Author

Collaborator

Код доехал до прода — 2026-09-12

Проверял маркерами в живом контейнере tradein-backend, не статусами джоб:

голых asyncio.to_thread( в app/services/geocoder.py   = 0   (было 12)
def run_db_thread в app/core/db.py                     = 1

PR #3460 merged (03d9745b).

Приёмка ещё НЕ выполнена — у неё есть дата

Критерий из issue — «ноль строк another operation is in progress / InvalidRequestError в логах tradein-backend за сутки под нагрузкой». Сегодня его проверить нельзя честно: контейнер пересоздан деплоем, окно docker logs — минуты, а не сутки. Любой ноль в нём недействителен (ровно та ловушка, из-за которой такие проверки и врут).

Проверить не раньше 2026-09-13 12:00 UTC, командой, которая сначала показывает, что чтение вообще состоялось:

ssh poincare 'docker inspect tradein-backend --format "{{.State.StartedAt}}";   docker logs --since 24h tradein-backend 2>&1 | wc -l;   docker logs --since 24h tradein-backend 2>&1 | grep -c -E "another operation is in progress|InvalidRequestError"'

Если StartedAt моложе суток — окно неполное, и число надо трактовать как «пока нечего сказать», а не как ноль.

Отдельно заведено по итогам ревью: #3463 (у запросов к БД нет ни statement_timeout, ни lock_timeout — ожидание осиротевшего потока не имеет верхней границы).

## Код доехал до прода — 2026-09-12 Проверял маркерами в живом контейнере `tradein-backend`, не статусами джоб: ``` голых asyncio.to_thread( в app/services/geocoder.py = 0 (было 12) def run_db_thread в app/core/db.py = 1 ``` PR #3460 merged (`03d9745b`). ## Приёмка ещё НЕ выполнена — у неё есть дата Критерий из issue — «ноль строк `another operation is in progress` / `InvalidRequestError` в логах `tradein-backend` за сутки под нагрузкой». Сегодня его проверить нельзя честно: контейнер пересоздан деплоем, окно `docker logs` — минуты, а не сутки. Любой ноль в нём недействителен (ровно та ловушка, из-за которой такие проверки и врут). **Проверить не раньше 2026-09-13 12:00 UTC**, командой, которая сначала показывает, что чтение вообще состоялось: ```bash ssh poincare 'docker inspect tradein-backend --format "{{.State.StartedAt}}"; docker logs --since 24h tradein-backend 2>&1 | wc -l; docker logs --since 24h tradein-backend 2>&1 | grep -c -E "another operation is in progress|InvalidRequestError"' ``` Если `StartedAt` моложе суток — окно неполное, и число надо трактовать как «пока нечего сказать», а не как ноль. Отдельно заведено по итогам ревью: #3463 (у запросов к БД нет ни `statement_timeout`, ни `lock_timeout` — ожидание осиротевшего потока не имеет верхней границы).

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

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

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