tradein/scraper: пропуск задачи не оставляет следа — статус «пропущено» построен и ни разу не использован, а алерт стоит в недостижимой ветке #2658

Closed
opened 2026-08-05 15:17:28 +00:00 by bot-backend · 2 comments
Collaborator

Найдено при разборе #2574. Повод — cian_history_backfill (расписание id=96) не выполняется с 29 июня, при этом включён и выглядит работающим: next_run_at исправно переставляется вперёд.

Что происходит

30 июня в 08:21 UTC истекли куки Циана (cian_session_cookies.expires_at_estimate). Гейт _cian_pre_claim при отсутствии кук делает ровно три вещи: пишет logger.warning, двигает next_run_at на следующее окно и возвращает False. Строка в scrape_runs не создаётся, last_run_at не трогается. Снаружи — «всё по расписанию», 37 дней подряд.

Конструктивная ошибка, из-за которой не сработал алерт

Sentry-алерт стоит во второй ветке — той, где verify_session вернул None. До неё исполнение не доходит никогда: load_session сам фильтрует expires_at_estimate > NOW() и на протухших куках отдаёт None ещё в первой, немой ветке.

Усугубляют две вещи: GlitchTip в контейнере скрапера настроен на event_level=ERROR (scheduler_main.py:59), поэтому warning событием не становится; а docker-логи теряются при каждом редеплое — я это увидел вживую, контейнер рестартовал в 11:43 и логов за 03:22 уже нет.

Почему монитор нулевых прогонов такое не ловит

По построению. CONSECUTIVE_ZERO_RESULT_ALERT_THRESHOLD проверяется только из mark_done/mark_failed/mark_banned — то есть требует уже существующей строки прогона. «Строк нет вовсе» — состояние, которое его SQL выразить не умеет.

Самое обидное

Правильный статус для громкого пропуска уже существует: 'skipped' заведён в перечислении ещё миграцией 015 и локализован во фронте как «пропущено». В проде у него 0 строк — полностью построенный и ни разу не использованный механизм.

Класс проблемы

pre_claim во всей кодовой базе ровно один (Циан), но механизм «отложить без строки прогона» общий: нашлось ещё 4 места в планировщике kit, которые пропускают наступившее расписание без следа в scrape_runs.

Что делать

  1. Писать строку scrape_runs со статусом 'skipped' и причиной вместо немого return False — во всех пяти местах. Механизм и локализация готовы.
  2. Поднять алерт в первую ветку (или, что честнее, отдельно проверять срок годности кук и предупреждать заранее, а не по факту протухания).
  3. Отдельно решить, как обновляются куки Циана — сейчас это ручная операция без напоминания, и она уже стоила 37 дней сбора истории.

Полезное следствие: как только пропуски станут строками, монитор нулевых прогонов начнёт их видеть без всяких доработок.

Связано: #2574, #2625, миграция 015.

Найдено при разборе #2574. Повод — `cian_history_backfill` (расписание id=96) не выполняется с 29 июня, при этом включён и выглядит работающим: `next_run_at` исправно переставляется вперёд. ## Что происходит 30 июня в 08:21 UTC истекли куки Циана (`cian_session_cookies.expires_at_estimate`). Гейт `_cian_pre_claim` при отсутствии кук делает ровно три вещи: пишет `logger.warning`, двигает `next_run_at` на следующее окно и возвращает `False`. Строка в `scrape_runs` **не создаётся**, `last_run_at` не трогается. Снаружи — «всё по расписанию», 37 дней подряд. ## Конструктивная ошибка, из-за которой не сработал алерт Sentry-алерт стоит во **второй** ветке — той, где `verify_session` вернул `None`. До неё исполнение не доходит **никогда**: `load_session` сам фильтрует `expires_at_estimate > NOW()` и на протухших куках отдаёт `None` ещё в первой, немой ветке. Усугубляют две вещи: GlitchTip в контейнере скрапера настроен на `event_level=ERROR` (`scheduler_main.py:59`), поэтому `warning` событием не становится; а docker-логи теряются при каждом редеплое — я это увидел вживую, контейнер рестартовал в 11:43 и логов за 03:22 уже нет. ## Почему монитор нулевых прогонов такое не ловит По построению. `CONSECUTIVE_ZERO_RESULT_ALERT_THRESHOLD` проверяется только из `mark_done`/`mark_failed`/`mark_banned` — то есть требует **уже существующей** строки прогона. «Строк нет вовсе» — состояние, которое его SQL выразить не умеет. ## Самое обидное Правильный статус для громкого пропуска **уже существует**: `'skipped'` заведён в перечислении ещё миграцией 015 и локализован во фронте как «пропущено». В проде у него **0 строк** — полностью построенный и ни разу не использованный механизм. ## Класс проблемы `pre_claim` во всей кодовой базе ровно один (Циан), но механизм «отложить без строки прогона» общий: нашлось ещё **4 места** в планировщике kit, которые пропускают наступившее расписание без следа в `scrape_runs`. ## Что делать 1. Писать строку `scrape_runs` со статусом `'skipped'` и причиной вместо немого `return False` — во всех пяти местах. Механизм и локализация готовы. 2. Поднять алерт в первую ветку (или, что честнее, отдельно проверять срок годности кук и предупреждать **заранее**, а не по факту протухания). 3. Отдельно решить, как обновляются куки Циана — сейчас это ручная операция без напоминания, и она уже стоила 37 дней сбора истории. Полезное следствие: как только пропуски станут строками, монитор нулевых прогонов начнёт их видеть без всяких доработок. Связано: #2574, #2625, миграция 015.
Author
Collaborator

Working on this in PR #2662

Working on this in PR #2662
Author
Collaborator

Сделано — PR #2662 смержен, деплой проверен.

Что в проде

mark_skipped в живом образе скрапера, фильтр GET /admin/scrape/runs?status=skipped отвечает 200 (до правки — 422, статус в перечисление API не входил). Строк со статусом «пропущено» пока ноль — и это ожидаемо: окно у cian_history_backfill ночное, 02:00–05:00 UTC.

Настоящий смоук будет в 03:22 UTC: должна появиться строка source=cian_history_backfill, status=skipped, причина про протухшие куки — вместо тридцать восьмого дня тишины. Проверю.

Что вышло за рамки исходного описания

Схлопывание подряд идущих пропусков. Два из пяти случаев (already_running, unknown_source) не двигают время следующего запуска, поэтому расписание переотбирается каждый тик — без схлопывания они писали бы строку раз в 60 секунд. Теперь обновляется последняя строка и растёт счётчик в counters, а разные причины не схлопываются между собой (в UPDATE стоит сверка причины).

При этом время начала обновляется, а начало стрика переезжает в отдельное поле. Иначе получалось бы обидное: список прогонов сортируется по времени запуска и отдаёт двадцать строк, поэтому 37-дневный пропуск с датой первого дня уходил бы вниз и пропадал с экрана — ровно в тот момент, когда он идёт прямо сейчас. Текст причины тоже освежается: без этого в строке, которую обновляют 37 дней, было бы написано «протухли 1 день назад».

Алерт поднят в достижимую ветку. Он стоял во второй, куда исполнение не доходит никогда: загрузчик сессии сам отсеивает протухшее и возвращает пусто ещё в первой, немой. Плюс уровень выбран с оглядкой на конфигурацию — в контейнере скрапера событиями становятся только записи уровня ERROR, предупреждение туда не долетело бы. И добавлено предупреждение заранее, за пять дней до протухания: честнее, чем сообщать по факту, когда сбор уже встал.

Чего сознательно не сделали

Пропуски не считаются нулевыми прогонами. «Полезное следствие» из моего описания сбылось лишь частично, и это правильно: пропуск — не «прогон вернул ноль лотов», смешивать их в одном счётчике значит испортить оба сигнала. Строки видны в базе и в интерфейсе, громкость даёт алерт, а монитор нулевых прогонов остался про своё.

Запись пропуска не обёрнута в свой try/except. Обоснование автора принято: если запись падает, то падает и создание прогона следующего расписания в том же тике — тик срывается в любом случае, а проглотить исключение значит вернуть немой пропуск, ради которого задача и заведена. Расписание остаётся наступившим и подхватится через 60 секунд.

Осталось общей задачей: строк со статусом «пропущено» не было ни одной за всю историю — механизм существовал с миграции 015, был локализован во фронте и ни разу не использовался. Теперь используется.

Сделано — PR #2662 смержен, деплой проверен. ## Что в проде `mark_skipped` в живом образе скрапера, фильтр `GET /admin/scrape/runs?status=skipped` отвечает **200** (до правки — 422, статус в перечисление API не входил). Строк со статусом «пропущено» пока **ноль** — и это ожидаемо: окно у `cian_history_backfill` ночное, 02:00–05:00 UTC. **Настоящий смоук будет в 03:22 UTC**: должна появиться строка `source=cian_history_backfill`, `status=skipped`, причина про протухшие куки — вместо тридцать восьмого дня тишины. Проверю. ## Что вышло за рамки исходного описания **Схлопывание подряд идущих пропусков.** Два из пяти случаев (`already_running`, `unknown_source`) не двигают время следующего запуска, поэтому расписание переотбирается каждый тик — без схлопывания они писали бы строку раз в 60 секунд. Теперь обновляется последняя строка и растёт счётчик в `counters`, а разные причины не схлопываются между собой (в UPDATE стоит сверка причины). При этом время начала **обновляется**, а начало стрика переезжает в отдельное поле. Иначе получалось бы обидное: список прогонов сортируется по времени запуска и отдаёт двадцать строк, поэтому 37-дневный пропуск с датой первого дня уходил бы вниз и пропадал с экрана — ровно в тот момент, когда он идёт прямо сейчас. Текст причины тоже освежается: без этого в строке, которую обновляют 37 дней, было бы написано «протухли 1 день назад». **Алерт поднят в достижимую ветку.** Он стоял во второй, куда исполнение не доходит никогда: загрузчик сессии сам отсеивает протухшее и возвращает пусто ещё в первой, немой. Плюс уровень выбран с оглядкой на конфигурацию — в контейнере скрапера событиями становятся только записи уровня ERROR, предупреждение туда не долетело бы. И добавлено предупреждение **заранее**, за пять дней до протухания: честнее, чем сообщать по факту, когда сбор уже встал. ## Чего сознательно не сделали **Пропуски не считаются нулевыми прогонами.** «Полезное следствие» из моего описания сбылось лишь частично, и это правильно: пропуск — не «прогон вернул ноль лотов», смешивать их в одном счётчике значит испортить оба сигнала. Строки видны в базе и в интерфейсе, громкость даёт алерт, а монитор нулевых прогонов остался про своё. **Запись пропуска не обёрнута в свой `try/except`.** Обоснование автора принято: если запись падает, то падает и создание прогона следующего расписания в том же тике — тик срывается в любом случае, а проглотить исключение значит вернуть немой пропуск, ради которого задача и заведена. Расписание остаётся наступившим и подхватится через 60 секунд. Осталось общей задачей: строк со статусом «пропущено» не было **ни одной за всю историю** — механизм существовал с миграции 015, был локализован во фронте и ни разу не использовался. Теперь используется.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
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#2658
No description provided.