fix(tradein/scraper): сигнал живости cian_history_backfill шлётся один раз — живые прогоны reap'ятся как zombie #2725

New issue

Closed

opened 2026-08-06 11:09:07 +00:00 by bot-backend · 1 comment

bot-backend commented

2026-08-06 11:09:07 +00:00

Collaborator

Найдено при разборе #2702 (отметки времени прогона), но это другой дефект: там время замерзало, здесь сигнала живости просто нет.

Факт

_execute_cian_backfill (app/services/scheduler.py) вызывает update_heartbeat один раз, до backfill_cian_history(), а сам батч (до 100 объявлений + 37 домов, каждый — браузерный fetch + sleep(delay≈5s)) не трогает heartbeat_at вообще. reap_zombies меряет ровно heartbeat_at с порогом 6 ч → прогон помечается zombie строго на 6-м часу, независимо от того, работает он или висит.

Правка #2718 (clock_timestamp() вместо now()) это НЕ чинит: она вернула честное время сигналу, который не посылают.

Замер на проде (2026-08-06)

Зомби всего 85 из 3300 прогонов. По источникам:

source	zombie	из них heartbeat не сдвинулся	max сдвиг heartbeat	max длительность
listing_source_snapshot	34	34	0.00 ч	6.02 ч
yandex_city_sweep	13	9	0.58 ч	6.58 ч
avito_city_sweep	13	4	1.54 ч	6.80 ч
cian_history_backfill	6	6	0.00 ч	6.01 ч
avito_full_load	5	0	0.51 ч	6.52 ч
cian_full_load	5	0	11.26 ч	17.27 ч
cian_city_sweep	3	0	0.33 ч	0.33 ч
house_imv_backfill	2	0	0.66 ч	6.67 ч
avito_detail_backfill	2	0	1.69 ч	7.70 ч
avito_full_load_exhaustive	1	0	0.65 ч	6.65 ч
geocode_missing_listings	1	0	0.15 ч	6.16 ч

У cian_history_backfill сдвиг heartbeat = 16-32 мс у всех шести (это и есть единственный стартовый вызов), и все шесть добиты ровно на started_at + 6.00 ч.

Прогоны были живые, а не висли

Единственный плановый писатель offer_price_history с source='cian' — это сам этот батч (остальные вызовы cian.detail.save_detail_enrichment — ручные админ-ручки admin.py:1907 и services/cian_price_history.py). Строки, записанные внутри окна каждого зомби-прогона:

run	окно	строк oph source=cian	первая строка после старта	последняя строка
101	06-16 19:50 → 01:51	98	+29 мс	+15 мин
135	06-17 20:41 → (не финализирован)	523	+19 мс	+1.75 ч
282	06-21 03:49 → 09:50	38	+33 мс	+2.10 ч
304	06-22 03:34 → 09:34	60	+22 мс	+5.40 ч
389	06-26 04:47 → 10:48	83	+26 мс	+2.54 ч
10	05-30 19:10 → 01:11	0	—	—

Пять из шести писали данные, один (304) — до 5.4 ч после старта, то есть был жив в момент, когда его назвали зависшим. Нормальная длительность этого источника подтверждена отдельно: прогон 346 отработал 18230 с = 5.06 ч (counters.duration_sec) — то есть источник штатно ходит вплотную к 6-часовому порогу.

Цена ошибки не только косметическая

mark_done обновляет WHERE id = :run_id AND status = 'running' — после пометки zombie собственный финал прогона становится no-op. Отсюда нулевые counters у всех шести строк: работа была, учёта её нет. Плюс has_running_run перестаёт видеть прогон и следующий тик планировщика может запустить второй такой же батч поверх работающего.

Что делать

Слать сигнал живости внутри батча (вариант «сигнал должен быть живым»), а не ослаблять критерий: zombie несёт побочную функцию — снимает running-блокировку источника (has_running_run), и без неё зависший прогон запер бы источник навсегда. Шаблон уже есть в репозитории: house_imv_backfill (heartbeat-колбэк каждые N домов, #1363), geocode_missing, *_detail_backfill.

Тем же шаблоном лечится и newbuilding_enrich — там ровно тот же единственный стартовый вызов (app/tasks/newbuilding_enrich_backfill.py:700) перед долгим циклом с задержками; на проде он пока не доезжал до порога (max 1.08 ч при limit=25), но это вопрос параметра.

Не входит: listing_source_snapshot (34 зомби) — там heartbeat невозможен по построению, вся работа — два set-based statement'а; вылечено иначе, в #2607 (statement_timeout), с 2026-08-02 прогоны укладываются в минуту.

Refs #2702

Найдено при разборе #2702 (отметки времени прогона), но это **другой** дефект: там время замерзало, здесь сигнала живости просто нет. ## Факт `_execute_cian_backfill` (`app/services/scheduler.py`) вызывает `update_heartbeat` **один раз, до** `backfill_cian_history()`, а сам батч (до 100 объявлений + 37 домов, каждый — браузерный fetch + `sleep(delay≈5s)`) не трогает `heartbeat_at` вообще. `reap_zombies` меряет ровно `heartbeat_at` с порогом 6 ч → прогон помечается `zombie` строго на 6-м часу, независимо от того, работает он или висит. Правка #2718 (`clock_timestamp()` вместо `now()`) это НЕ чинит: она вернула честное время сигналу, который не посылают. ### Замер на проде (2026-08-06) Зомби всего 85 из 3300 прогонов. По источникам: | source | zombie | из них heartbeat не сдвинулся | max сдвиг heartbeat | max длительность | |---|---|---|---|---| | listing_source_snapshot | 34 | 34 | 0.00 ч | 6.02 ч | | yandex_city_sweep | 13 | 9 | 0.58 ч | 6.58 ч | | avito_city_sweep | 13 | 4 | 1.54 ч | 6.80 ч | | **cian_history_backfill** | **6** | **6** | **0.00 ч** | **6.01 ч** | | avito_full_load | 5 | 0 | 0.51 ч | 6.52 ч | | cian_full_load | 5 | 0 | 11.26 ч | 17.27 ч | | cian_city_sweep | 3 | 0 | 0.33 ч | 0.33 ч | | house_imv_backfill | 2 | 0 | 0.66 ч | 6.67 ч | | avito_detail_backfill | 2 | 0 | 1.69 ч | 7.70 ч | | avito_full_load_exhaustive | 1 | 0 | 0.65 ч | 6.65 ч | | geocode_missing_listings | 1 | 0 | 0.15 ч | 6.16 ч | У `cian_history_backfill` сдвиг heartbeat = 16-32 **мс** у всех шести (это и есть единственный стартовый вызов), и все шесть добиты ровно на `started_at + 6.00 ч`. ### Прогоны были живые, а не висли Единственный плановый писатель `offer_price_history` с `source='cian'` — это сам этот батч (остальные вызовы `cian.detail.save_detail_enrichment` — ручные админ-ручки `admin.py:1907` и `services/cian_price_history.py`). Строки, записанные внутри окна каждого зомби-прогона: | run | окно | строк oph source=cian | первая строка после старта | последняя строка | |---|---|---|---|---| | 101 | 06-16 19:50 → 01:51 | 98 | +29 мс | +15 мин | | 135 | 06-17 20:41 → (не финализирован) | 523 | +19 мс | +1.75 ч | | 282 | 06-21 03:49 → 09:50 | 38 | +33 мс | +2.10 ч | | 304 | 06-22 03:34 → 09:34 | 60 | +22 мс | **+5.40 ч** | | 389 | 06-26 04:47 → 10:48 | 83 | +26 мс | +2.54 ч | | 10 | 05-30 19:10 → 01:11 | 0 | — | — | Пять из шести писали данные, один (304) — до 5.4 ч после старта, то есть был жив в момент, когда его назвали зависшим. Нормальная длительность этого источника подтверждена отдельно: прогон 346 отработал 18230 с = **5.06 ч** (`counters.duration_sec`) — то есть источник штатно ходит вплотную к 6-часовому порогу. ### Цена ошибки не только косметическая `mark_done` обновляет `WHERE id = :run_id AND status = 'running'` — после пометки `zombie` собственный финал прогона становится no-op. Отсюда нулевые `counters` у всех шести строк: работа была, учёта её нет. Плюс `has_running_run` перестаёт видеть прогон и следующий тик планировщика может запустить второй такой же батч поверх работающего. ## Что делать Слать сигнал живости внутри батча (вариант «сигнал должен быть живым»), а не ослаблять критерий: `zombie` несёт побочную функцию — снимает `running`-блокировку источника (`has_running_run`), и без неё зависший прогон запер бы источник навсегда. Шаблон уже есть в репозитории: `house_imv_backfill` (`heartbeat`-колбэк каждые N домов, #1363), `geocode_missing`, `*_detail_backfill`. Тем же шаблоном лечится и `newbuilding_enrich` — там ровно тот же единственный стартовый вызов (`app/tasks/newbuilding_enrich_backfill.py:700`) перед долгим циклом с задержками; на проде он пока не доезжал до порога (max 1.08 ч при `limit=25`), но это вопрос параметра. Не входит: `listing_source_snapshot` (34 зомби) — там heartbeat невозможен по построению, вся работа — два set-based statement'а; вылечено иначе, в #2607 (`statement_timeout`), с 2026-08-02 прогоны укладываются в минуту. Refs #2702

Light1YT referenced this issue from a commit

2026-08-06 11:19:23 +00:00

fix(tradein/scraper): сигнал живости из середины батча — живые прогоны перестают числиться зависшими (#2725)

bot-backend referenced this issue

2026-08-06 11:19:50 +00:00

fix(tradein/scraper): сигнал живости из середины батча — живые прогоны перестают числиться зависшими (#2725) #2727

bot-backend referenced this issue from a commit

2026-08-06 11:30:53 +00:00

fix(tradein/scraper): сигнал живости из середины батча — живые прогоны перестают числиться зависшими (#2725) (#2727)

bot-backend commented

2026-08-06 12:12:58 +00:00

Author

Collaborator

Смержено PR #2727, прод-верификация 2026-08-06 12:0x UTC — по коду в живых контейнерах, не по зелёному деплою (в тот же деплой попал чужой #2729, мерж за 10 с до моего, поэтому проверял отдельно):

docker exec tradein-scraper grep -c "on_progress=_heartbeat" /app/app/services/scheduler.py            → 1
docker exec tradein-scraper grep -c "on_progress=_heartbeat" /app/app/tasks/newbuilding_enrich_backfill.py → 1
docker exec tradein-scraper grep -n  "on_progress" /app/app/tasks/cian_history_backfill.py            → сигнатура + оба вызова в циклах
docker exec tradein-backend  grep -c "on_progress=_heartbeat" /app/app/services/scheduler.py           → 1

Контейнеры пересозданы (paths-filter scraper включает app/services/scheduler.py и app/tasks/**).

Проверка НА ДАННЫХ отложена до ближайших прогонов — запускать живые скрейпы вручную нельзя:

newbuilding_enrich — 2026-08-07 00:39 UTC;
cian_history_backfill — 2026-08-07 02:02 UTC (сейчас источник уходит в skipped: куки Циана протухли 2026-06-30, так что первым честным замером будет newbuilding_enrich).

Ожидаемое: heartbeat_at > started_at при ненулевых counters в середине работы:

SELECT id, status, started_at, heartbeat_at,
       EXTRACT(EPOCH FROM (heartbeat_at - started_at)) AS hb_adv_s, counters
FROM scrape_runs WHERE source IN ('newbuilding_enrich','cian_history_backfill')
ORDER BY started_at DESC LIMIT 3;

До правки у зомби-прогонов этого класса hb_adv_s был 0.016-0.032.

Смержено PR #2727, прод-верификация 2026-08-06 12:0x UTC — **по коду в живых контейнерах**, не по зелёному деплою (в тот же деплой попал чужой #2729, мерж за 10 с до моего, поэтому проверял отдельно): ``` docker exec tradein-scraper grep -c "on_progress=_heartbeat" /app/app/services/scheduler.py → 1 docker exec tradein-scraper grep -c "on_progress=_heartbeat" /app/app/tasks/newbuilding_enrich_backfill.py → 1 docker exec tradein-scraper grep -n "on_progress" /app/app/tasks/cian_history_backfill.py → сигнатура + оба вызова в циклах docker exec tradein-backend grep -c "on_progress=_heartbeat" /app/app/services/scheduler.py → 1 ``` Контейнеры пересозданы (paths-filter `scraper` включает `app/services/scheduler.py` и `app/tasks/**`). Проверка НА ДАННЫХ отложена до ближайших прогонов — запускать живые скрейпы вручную нельзя: * `newbuilding_enrich` — 2026-08-07 00:39 UTC; * `cian_history_backfill` — 2026-08-07 02:02 UTC (сейчас источник уходит в `skipped`: куки Циана протухли 2026-06-30, так что первым честным замером будет newbuilding_enrich). Ожидаемое: `heartbeat_at > started_at` при ненулевых `counters` в середине работы: ```sql SELECT id, status, started_at, heartbeat_at, EXTRACT(EPOCH FROM (heartbeat_at - started_at)) AS hb_adv_s, counters FROM scrape_runs WHERE source IN ('newbuilding_enrich','cian_history_backfill') ORDER BY started_at DESC LIMIT 3; ``` До правки у зомби-прогонов этого класса `hb_adv_s` был 0.016-0.032.

bot-backend closed this issue

2026-08-06 12:12:58 +00:00