From 46bbb7988102b1b6a76aa3df1b4a3d44b463169f Mon Sep 17 00:00:00 2001 From: bot-backend Date: Thu, 6 Aug 2026 02:29:11 +0500 Subject: [PATCH 1/2] =?UTF-8?q?fix(tradein):=20=D1=81=D0=B8=D0=B3=D0=BD?= =?UTF-8?q?=D0=B0=D0=BB=D1=8B=20=D0=BE=20=D1=81=D0=B1=D0=BE=D1=8F=D1=85=20?= =?UTF-8?q?=D0=BD=D0=B0=D0=BA=D0=BE=D0=BD=D0=B5=D1=86=20=D1=81=D1=82=D0=B0?= =?UTF-8?q?=D0=BD=D0=BE=D0=B2=D1=8F=D1=82=D1=81=D1=8F=20=D1=81=D0=BE=D0=B1?= =?UTF-8?q?=D1=8B=D1=82=D0=B8=D1=8F=D0=BC=D0=B8,=20=D0=B0=20=D0=BF=D1=80?= =?UTF-8?q?=D0=BE=D1=82=D1=83=D1=85=D0=B0=D0=BD=D0=B8=D0=B5=20=D0=BA=D1=83?= =?UTF-8?q?=D0=BA=20=D0=BF=D1=80=D0=B5=D0=B4=D1=83=D0=BF=D1=80=D0=B5=D0=B6?= =?UTF-8?q?=D0=B4=D0=B0=D0=B5=D1=82=20=D0=B7=D0=B0=D1=80=D0=B0=D0=BD=D0=B5?= =?UTF-8?q?=D0=B5=20(#2674)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit В скрапер-контейнере GlitchTip поднят с LoggingIntegration(event_level=ERROR), поэтому любой сигнал уровня WARNING событием не становится — сколько бы раз он ни срабатывал. Прод это подтвердил: монитор устаревания СберИндекса отработал 24 раза, 9 из них со staleness-вердиктом, событий ноль; куки Домклика протухли 2026-08-03 и об этом никто не узнал. Разбирали не «поменять warning на error», а по каждому сигналу: сбой, из-за которого данные перестают обновляться — событие; рутина и ожидаемые состояния — лог. Плюс предупреждение ЗАРАНЕЕ там, где чинить нужно руками (куки Домклика — по образцу #2658 для Циана, переиспользован тот же подход session_expires_at + COOKIE_EXPIRY_WARN_DAYS). У поллера Росреестра выход нового квартала оставлен уровнем info, но получил явный capture_message(level="info"): новость хорошая, но требует ручного импорта оператором, а INFO-строка живёт только до ближайшего редеплоя. logger.error для неё был бы враньём в error-rate и стрик-алертах. Оговорка: у GlitchTip-проекта сейчас нет ни правил, ни получателей (#2673) — события станут видны в интерфейсе, но никому не отправятся. Refs #2674 --- .../backend/app/services/domclick_session.py | 39 ++ .../backend/app/services/rosreestr_poll.py | 48 ++- .../backend/app/services/sber_index.py | 10 +- .../app/tasks/deals_freshness_monitor.py | 4 +- .../app/tasks/domclick_detail_backfill.py | 76 +++- .../app/tasks/sber_freshness_monitor.py | 23 +- .../tasks/test_domclick_detail_backfill.py | 52 +-- .../tests/test_alerts_become_events.py | 349 ++++++++++++++++++ tradein-mvp/backend/tests/test_sber_index.py | 15 +- 9 files changed, 565 insertions(+), 51 deletions(-) create mode 100644 tradein-mvp/backend/tests/test_alerts_become_events.py diff --git a/tradein-mvp/backend/app/services/domclick_session.py b/tradein-mvp/backend/app/services/domclick_session.py index 177ee772..85fdef97 100644 --- a/tradein-mvp/backend/app/services/domclick_session.py +++ b/tradein-mvp/backend/app/services/domclick_session.py @@ -17,6 +17,7 @@ from __future__ import annotations import json import logging +from datetime import datetime from sqlalchemy import text from sqlalchemy.orm import Session @@ -25,6 +26,13 @@ from app.core.config import settings logger = logging.getLogger(__name__) +# За сколько дней до протухания кук предупреждать (#2674, по образцу #2658 для Циана). +# Обновление кук — РУЧНАЯ операция (залить дамп через админку), человеку нужен запас: +# сигнал по факту протухания приходит, когда обогащение уже встало. Прод 2026-08-03: +# куки протухли, единственным следом был WARNING в docker-логе, который к тому же +# теряется при редеплое. save_session ставит ttl 30 дней, так что окно широкое. +COOKIE_EXPIRY_WARN_DAYS = 5 + # Cookies критичные для DomClick auth (Sber ID) — фильтр перед сохранением. # Список составлен по реальному DevTools/Cookie-Editor дампу авторизованной # test-аккаунт сессии (Sber ID login), 2026-07-04. @@ -148,6 +156,37 @@ def load_session(db: Session) -> dict[str, str] | None: return cookies +def session_expires_at(db: Session, *, valid_only: bool = False) -> datetime | None: + """Когда протухают самые свежезагруженные куки (#2674, зеркалит cian_session #2658). + + `load_session` отбирает только ещё валидные записи (expires_at_estimate > NOW()) и на + протухших отдаёт None — вызывающий не мог отличить «кук никогда не загружали» от + «протухли позавчера» и не мог предупредить ЗАРАНЕЕ. + + valid_only=False (диагностика после None от load_session) — свежайшая запись любая: + валидных по определению нет, нужен именно срок протухшей. valid_only=True — та же + запись, которую взял бы load_session: для предупреждения «скоро протухнут» нужен срок + ИМЕННО используемых кук, иначе при нескольких аккаунтах посчитаем по чужой строке. + """ + row = db.execute( + text( + """ + SELECT expires_at_estimate FROM domclick_session_cookies + WHERE NOT CAST(:valid_only AS boolean) + OR (expires_at_estimate > NOW() + AND (last_invalid_at IS NULL OR last_invalid_at < uploaded_at)) + ORDER BY uploaded_at DESC + LIMIT 1 + """ + ), + {"valid_only": valid_only}, + ).first() + if row is None: + return None + expires_at: datetime | None = row[0] + return expires_at + + def mark_session_invalid(db: Session, account_cas_id: int) -> None: """Flag session как expired/invalid (например после блока во время scrape).""" db.execute( diff --git a/tradein-mvp/backend/app/services/rosreestr_poll.py b/tradein-mvp/backend/app/services/rosreestr_poll.py index 1ef1d8df..3fa293b0 100644 --- a/tradein-mvp/backend/app/services/rosreestr_poll.py +++ b/tradein-mvp/backend/app/services/rosreestr_poll.py @@ -50,9 +50,18 @@ sber_index.py для sberindex.ru (см. #922, тот же паттерн: пу отвечает HTTP 403 без браузерного User-Agent — шлём Chrome UA (тот же паттерн, что DEFAULT_UA в zhkh_flats_loader.py). -При сетевой ошибке / HTTP 5xx / таймауте — логируем warning, возвращаем -available=False. Отсутствие папки/файла квартала → available=False (штатный -случай до публикации квартала, до начала следующего месяца после конца квартала). +УРОВНИ СИГНАЛОВ (#2674 — в контейнере скрапера событием GlitchTip становится только +запись ERROR, см. scheduler_main.py LoggingIntegration(event_level=ERROR)): + - Портал ответил не-200 на листинг каталога/папки → ERROR. Каталог — единственная + опора поллера; портал УЖЕ один раз переехал (см. "ИСТОРИЯ"), и тогда поллер молча + врал целыми кварталами. Такое обязано быть событием. + - Таймаут / сетевая ошибка → WARNING, как раньше. Это транспортный блип раз в месяц + (такт поллера), сам пройдёт; а «квартал так и не приехал» ловит отдельный + deals_freshness_monitor ERROR-ом по max(deal_date). + - Папки/файла квартала нет → INFO. Штатное состояние до публикации: квартал выходит + 4 раза в год, поллер ходит 12 — большинство прогонов ЗАКОННО пустые. + - Квартал вышел → INFO + ЯВНОЕ событие capture_message(level="info"), см. + poll_rosreestr_new_quarter. """ from __future__ import annotations @@ -63,6 +72,7 @@ from typing import Any from urllib.parse import quote, unquote, urljoin import httpx +import sentry_sdk from sqlalchemy import text from sqlalchemy.orm import Session @@ -243,7 +253,8 @@ async def check_new_quarter_available( try: index_resp = await client.get(_DATA_SETS_BASE_URL, follow_redirects=True) if index_resp.status_code != 200: - logger.warning( + # ERROR (#2674): без каталога поллер слеп — см. "УРОВНИ СИГНАЛОВ". + logger.error( "rosreestr_poll: unexpected HTTP %d listing %s — treating Q%d %d as unavailable", index_resp.status_code, _DATA_SETS_BASE_URL, @@ -265,7 +276,9 @@ async def check_new_quarter_available( folder_url = urljoin(_DATA_SETS_BASE_URL, folder_href) folder_resp = await client.get(folder_url, follow_redirects=True) if folder_resp.status_code != 200: - logger.warning( + # ERROR (#2674): папка квартала НАЙДЕНА в каталоге, но не открывается — + # это уже не «ещё не опубликовали», а поломка портала. + logger.error( "rosreestr_poll: unexpected HTTP %d listing folder %s — " "treating Q%d %d as unavailable", folder_resp.status_code, @@ -338,12 +351,14 @@ async def check_new_quarter_available( exc, ) return False - except Exception as exc: - logger.warning( - "rosreestr_poll: unexpected error checking Q%d %d: %s — treating as unavailable", + except Exception: + # ERROR + traceback (#2674): сюда попадает НАШ баг (сменилась разметка, упал + # парсер href'ов), а не сбой сети. Под WARNING он молча превращался в + # «квартала нет» — ровно тот сценарий, из-за которого поллер врал кварталами. + logger.exception( + "rosreestr_poll: unexpected error checking Q%d %d — treating as unavailable", quarter, year, - exc, ) return False @@ -409,6 +424,21 @@ async def poll_rosreestr_new_quarter(db: Session) -> dict[str, Any]: rosreestr_dataset_url(next_year, next_quarter), _DATA_SETS_BASE_URL, ) + # #2674: это ХОРОШАЯ новость, но она требует ручного шага оператора (импорт + # много-гигабайтного ZIP), а INFO-строка живёт только в docker-логах и + # теряется на редеплое. Отсюда явный capture_message вместо logger.error: + # событие в GlitchTip будет, а error-rate и стрик-алерты не соврут «сбой». + # Шума не создаёт: такт поллера — раз в 28 дней, квартал выходит 4 раза в + # год, а повтор до самого импорта — это и есть нужное напоминание (#2670). + try: + sentry_sdk.capture_message( + f"Rosreestr: доступен новый квартал Q{next_quarter} {next_year} — " + "нужен ручной импорт (02_load_all_quarters.sh + import-rosreestr.sh)", + level="info", + ) + except Exception: + # Алертинг best-effort: падение отправки события не должно валить поллер. + logger.warning("rosreestr_poll: capture_message failed", exc_info=True) return { "available": available, diff --git a/tradein-mvp/backend/app/services/sber_index.py b/tradein-mvp/backend/app/services/sber_index.py index 36b7bc95..7a4d646c 100644 --- a/tradein-mvp/backend/app/services/sber_index.py +++ b/tradein-mvp/backend/app/services/sber_index.py @@ -464,8 +464,16 @@ async def pull_sber_indices( # path or its filter dims are stale (sber renames slugs / changes # dimension codes). Surface it loudly with the slug + filter so the # next breakage is diagnosable instead of a silent error-counter bump. + # + # #2674: "loudly" было сказано, но написано WARNING — тише, чем + # соседние 5xx/сетевые ветки, и НЕ событие в скрапере + # (LoggingIntegration event_level=ERROR). При этом 404 — самая + # ПЕРМАНЕНТНАЯ из трёх: 5xx и сетевой сбой сами пройдут, а + # переименованный slug будет 404-ить каждый месяц, пока человек не + # перезахватит dataset-path. Ровно тот сбой, из-за которого бенчмарк + # перестаёт обновляться. if exc.response.status_code == 404: - logger.warning( + logger.error( "sber_index: 404 for dashboard=%s ref_area=%s filter=%s — " "dataset-path invalid? slug renamed or filter dims stale " "(re-capture /dataset/v1/ via dashboard route-interception)", diff --git a/tradein-mvp/backend/app/tasks/deals_freshness_monitor.py b/tradein-mvp/backend/app/tasks/deals_freshness_monitor.py index b585551c..db7440c1 100644 --- a/tradein-mvp/backend/app/tasks/deals_freshness_monitor.py +++ b/tradein-mvp/backend/app/tasks/deals_freshness_monitor.py @@ -142,7 +142,9 @@ def check_deals_freshness( row = db.execute(_LATEST_DEAL_DATE_SQL).first() latest: date | None = row.latest if row is not None else None if latest is None: - logger.warning( + # ERROR (#2674): монитор не может выполнить работу — сбой, а не наблюдение. + # Соседняя ветка (overdue) писала ERROR с самого начала; эта расходилась. + logger.error( "deals freshness: таблица deals пуста/недоступна — оценить свежесть нельзя" ) runs_mod.mark_failed(db, run_id, "deals empty or unavailable", counters) diff --git a/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py b/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py index 319e9f95..ce158121 100644 --- a/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py +++ b/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py @@ -52,10 +52,16 @@ Exception triad differs from Avito: Cookie injection is mandatory wiring, not optional: cookies are loaded ONCE per run. If None (no valid session uploaded / expired) -- the run still proceeds (cookie- injection is a QRATOR-defeat mechanism, not a hard requirement; organic SERP-origin -navigation from PR #2430 still applies) but a warning is logged once at run start so +navigation from PR #2430 still applies) but an ERROR is logged once at run start so operators notice the test-account session needs refreshing via `POST /scrape/domclick/upload-cookies` (no auto-login -- documented MVP limitation, see app/services/domclick_session.py module docstring). + +#2674: раньше это был WARNING, который в скрапер-контейнере событием не становится +(LoggingIntegration event_level=ERROR) — куки протухли 2026-08-03 и об этом никто не +узнал. Теперь два сигнала вместо одного: ERROR по факту (_alert_domclick_cookies) и +ERROR ЗАРАНЕЕ, пока куки ещё живы (_warn_before_domclick_cookies_expire) — по образцу +#2658 для Циана, ручное обновление кук требует запаса времени. """ from __future__ import annotations @@ -65,6 +71,7 @@ import logging import random import time from dataclasses import dataclass, field +from datetime import UTC, datetime, timedelta from scraper_kit.browser_fetcher import BrowserFetcher from scraper_kit.domclick_exceptions import DomClickBlockedError, DomClickParseError @@ -85,6 +92,60 @@ __all__ = [ ] +def _alert_domclick_cookies(db: Session, run_id: int) -> None: + """Громкий сигнал «обогащение идёт без кук» — logger.error, не warning (#2674). + + В контейнере скрапера GlitchTip поднят с LoggingIntegration(event_level=ERROR) + (scheduler_main.py), поэтому прежний WARNING событием не становился: куки протухли + на проде 2026-08-03, и единственным следом была строка в docker-логе, которая + теряется при редеплое. Прогон при этом НЕ прерываем — cookie-инъекция это + механизм обхода QRATOR, а не жёсткое требование (см. докстринг модуля), — но + состояние требует ручного действия человека, значит должно быть событием. + + Причину различаем так же, как #2658 у Циана: «кук нет вовсе» и «протухли N дней + назад» лечатся одинаково, но диагностируются по-разному. + """ + expires_at = domclick_session_svc.session_expires_at(db) + now = datetime.now(tz=UTC) + if expires_at is None: + detail = "кук DomClick нет в БД" + elif expires_at <= now: + detail = ( + f"куки DomClick протухли {expires_at:%Y-%m-%d} " + f"({(now - expires_at).days} дн. назад)" + ) + else: + detail = "куки DomClick помечены невалидными (last_invalid_at)" + logger.error( + "domclick_detail_backfill: run_id=%d — %s; обогащение идёт БЕЗ cookie-инъекции " + "(QRATOR-обход деградировал до organic SERP-origin навигации, PR #2430). " + "Перезалейте сессию test-аккаунта: POST /scrape/domclick/upload-cookies", + run_id, + detail, + ) + + +def _warn_before_domclick_cookies_expire(db: Session, run_id: int) -> None: + """Предупредить ЗАРАНЕЕ, пока куки ещё рабочие (#2674, образец — #2658 для Циана). + + Сигнал по факту протухания приходит, когда обогащение уже встало; обновление кук + ручное, человеку нужен запас. valid_only=True — срок ИМЕННО той записи, которую + взял load_session (при нескольких аккаунтах свежайшая-любая может быть чужой). + """ + expires_at = domclick_session_svc.session_expires_at(db, valid_only=True) + if expires_at is None: + return + left = expires_at - datetime.now(tz=UTC) + if left <= timedelta(days=domclick_session_svc.COOKIE_EXPIRY_WARN_DAYS): + logger.error( + "domclick_detail_backfill: run_id=%d — куки DomClick протухнут %s " + "(осталось %.1f дн.); обновите заранее, иначе обогащение деградирует молча", + run_id, + expires_at.date().isoformat(), + left.total_seconds() / 86400, + ) + + @dataclass class DomClickDetailBackfillResult: """Counters for one backfill run.""" @@ -135,16 +196,13 @@ async def run_domclick_detail_backfill( try: # Cookie injection (#2000 PR #2433) -- loaded ONCE per run, threaded into every - # fetch_detail() call below. None is a valid (degraded) state, not an error. + # fetch_detail() call below. Прогон продолжается и без кук (см. докстринг), но + # это состояние требует ЧЕЛОВЕКА: обновление сессии — ручная операция. cookies = domclick_session_svc.load_session(db) if cookies is None: - logger.warning( - "domclick_detail_backfill: run_id=%d -- no valid DomClick session cookies " - "in DB; proceeding WITHOUT cookie-injection (QRATOR-defeat degraded to " - "organic SERP-origin navigation only, PR #2430). Refresh test-account " - "session via POST /scrape/domclick/upload-cookies.", - run_id, - ) + _alert_domclick_cookies(db, run_id) + else: + _warn_before_domclick_cookies_expire(db, run_id) runs_mod.update_heartbeat(db, run_id, current_counters) diff --git a/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py b/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py index 00e49fdc..22193491 100644 --- a/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py +++ b/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py @@ -9,9 +9,17 @@ видна только в debug-подобном per-estimate warning'е, тонущем в логах оценок. Этот монитор смотрит на `max(period_month)` вторичного сегмента по региону и -поднимает per-day WARNING-алерт, когда данные устарели СВЕРХ допустимого лага +поднимает per-day ERROR-алерт, когда данные устарели СВЕРХ допустимого лага публикации — так ops видит дрейф на MONITOR-частоте, а не по крупицам в логах. +#2674 — почему ERROR, а не WARNING. В контейнере скрапера GlitchTip поднят с +LoggingIntegration(event_level=ERROR) (scheduler_main.py), поэтому WARNING +событием НЕ становится: на проде монитор отработал 24 раза, из них 9 со +staleness-вердиктом — и ни одного события. Бенчмарк цен участвует в сверке наших +медиан, его застой — сбой, а не наблюдение. Сосед по конструкции +(deals_freshness_monitor) писал ERROR с самого начала — расходилась только эта +джоба. + Порог алерта (документирование выбора): Per-estimate guard (estimator): age > settings.sber_index_max_age_days (35д). Монитор: age > sber_index_max_age_days + lag_allowance. @@ -27,8 +35,8 @@ kit-scheduler'ом через product_handlers._job_sber_freshness_monitor в run_in_executor, по образцу deals_freshness_monitor. Вердикт вычисляет ЧИСТАЯ функция evaluate_sber_freshness() (frozen-now тестируется без БД). -Прогон НЕ помечается failed при алерте (это МОНИТОР, а не сбой джобы) — WARNING -достаточен. mark_failed только если sber_price_index недоступна/пуста (нечего +Прогон НЕ помечается failed при алерте (это МОНИТОР, а не сбой джобы) — ERROR-записи +достаточно. mark_failed только если sber_price_index недоступна/пуста (нечего оценивать). """ @@ -136,7 +144,10 @@ def check_sber_freshness( row = db.execute(_LATEST_SBER_PERIOD_SQL, {"city": SBER_MONITOR_CITY}).first() latest: date | None = row.latest if row is not None else None if latest is None: - logger.warning( + # ERROR (#2674): монитор не может выполнить свою работу вовсе — это сбой, + # а не наблюдение. mark_failed ниже виден только стрик-алерту (3 подряд), + # а монитор ходит раз в сутки — три дня молчания на пустом бенчмарке. + logger.error( "sber freshness: sber_price_index пуст/недоступен для region=%s " "(вторичка) — оценить свежесть нельзя", SBER_MONITOR_CITY, @@ -156,7 +167,9 @@ def check_sber_freshness( } if verdict.stale: - logger.warning( + # ERROR (#2674): WARNING не долетает до GlitchTip (event_level=ERROR) — + # 9 срабатываний на проде дали ноль событий. См. докстринг модуля. + logger.error( "sber freshness: max(period_month)=%s устарел на %d дней " "(> порога %d = sber_index_max_age_days %d + lag %d); " "СберИндекс time-adjustment ДКП-сделок мог отстать — " diff --git a/tradein-mvp/backend/tests/tasks/test_domclick_detail_backfill.py b/tradein-mvp/backend/tests/tasks/test_domclick_detail_backfill.py index 2cacce98..dd2b28f6 100644 --- a/tradein-mvp/backend/tests/tasks/test_domclick_detail_backfill.py +++ b/tradein-mvp/backend/tests/tasks/test_domclick_detail_backfill.py @@ -9,8 +9,10 @@ _mock_db(snapshot) helper, runs = MagicMock() assertions. DomClick-специф from __future__ import annotations +import logging import os import sys +from datetime import UTC, datetime, timedelta from unittest.mock import AsyncMock, MagicMock, patch os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:5432/test") @@ -60,6 +62,20 @@ def _mock_db(snapshot: list[dict]) -> MagicMock: return db +def _mock_session_svc(cookies: dict[str, str] | None) -> MagicMock: + """Fake domclick_session модуль: load_session + срок годности кук (#2674). + + session_expires_at по умолчанию далеко в будущем — иначе каждый тест ловил бы + предупреждение «куки скоро протухнут». Отдельно оно проверяется в + tests/test_alerts_become_events.py. + """ + svc = MagicMock() + svc.load_session.return_value = cookies + svc.COOKIE_EXPIRY_WARN_DAYS = 5 + svc.session_expires_at.return_value = datetime.now(tz=UTC) + timedelta(days=30) + return svc + + def _mock_browser_fetcher_cls() -> MagicMock: """MagicMock class whose instance is a working async context manager.""" instance = AsyncMock() @@ -88,8 +104,7 @@ async def test_backfill_empty_snapshot_marks_done() -> None: db = _mock_db([]) runs = MagicMock() fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -123,8 +138,7 @@ async def test_backfill_processes_snapshot_with_cookies_threaded() -> None: mock_save = MagicMock(return_value=True) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") fake_cookies = {"CAS_ID": "999", "qrator_jsid2": "abc"} - mock_svc = MagicMock() - mock_svc.load_session.return_value = fake_cookies + mock_svc = _mock_session_svc(fake_cookies) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -156,9 +170,10 @@ async def test_backfill_processes_snapshot_with_cookies_threaded() -> None: @pytest.mark.asyncio -async def test_backfill_cookies_none_still_proceeds_with_warning(caplog) -> None: +async def test_backfill_cookies_none_still_proceeds_with_error_alert(caplog) -> None: """No valid session (load_session()->None) -> run still proceeds (fetch_detail - called with cookies=None), but a warning is logged so operators refresh the session. + called with cookies=None), но сигнал теперь ERROR, а не WARNING (#2674): в + скрапер-контейнере событием GlitchTip становится только ERROR. """ snapshot = _make_snapshot(1) db = _mock_db(snapshot) @@ -167,8 +182,8 @@ async def test_backfill_cookies_none_still_proceeds_with_warning(caplog) -> None mock_fetch = AsyncMock(return_value=mock_enrichment) mock_save = MagicMock(return_value=True) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = None + mock_svc = _mock_session_svc(None) + mock_svc.session_expires_at.return_value = None # кук никогда не загружали mock_bf_cls = _mock_browser_fetcher_cls() with ( caplog.at_level("WARNING"), @@ -187,7 +202,8 @@ async def test_backfill_cookies_none_still_proceeds_with_warning(caplog) -> None assert result.enriched == 1 _, kwargs = mock_fetch.call_args assert kwargs.get("cookies") is None - assert "no valid DomClick session cookies" in caplog.text + assert "кук DomClick нет в БД" in caplog.text + assert [r for r in caplog.records if r.levelno >= logging.ERROR] runs.mark_done.assert_called_once() runs.mark_failed.assert_not_called() @@ -205,8 +221,7 @@ async def test_backfill_blocked_abort_after_max_consecutive() -> None: blocked_exc = DomClickBlockedError("QRATOR challenge page detected") mock_fetch = AsyncMock(side_effect=blocked_exc) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -243,8 +258,7 @@ async def test_backfill_parse_error_counts_failed_no_abort() -> None: ) mock_save = MagicMock(return_value=True) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -281,8 +295,7 @@ async def test_backfill_sigterm_drain_breaks_and_marks_done_partial() -> None: mock_fetch = AsyncMock(return_value=mock_enrichment) mock_save = MagicMock(return_value=True) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -316,8 +329,7 @@ async def test_backfill_budget_guard_stops_loop() -> None: runs = MagicMock() mono_values = iter([0.0, 999.0, 999.0]) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -340,8 +352,7 @@ async def test_backfill_top_level_exception_marks_failed() -> None: db.execute.side_effect = RuntimeError("DB connection lost") runs = MagicMock() fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), @@ -367,8 +378,7 @@ async def test_backfill_generic_exception_continues_and_rolls_back() -> None: mock_enrichment = MagicMock() mock_fetch = AsyncMock(side_effect=[RuntimeError("unexpected"), mock_enrichment]) fake_settings = MagicMock(browser_http_endpoint="http://browser:9000") - mock_svc = MagicMock() - mock_svc.load_session.return_value = {"CAS_ID": "123"} + mock_svc = _mock_session_svc({"CAS_ID": "123"}) mock_bf_cls = _mock_browser_fetcher_cls() with ( patch(_SETTINGS, fake_settings), diff --git a/tradein-mvp/backend/tests/test_alerts_become_events.py b/tradein-mvp/backend/tests/test_alerts_become_events.py new file mode 100644 index 00000000..a58d5910 --- /dev/null +++ b/tradein-mvp/backend/tests/test_alerts_become_events.py @@ -0,0 +1,349 @@ +"""Сигналы о сбоях действительно становятся событиями GlitchTip (#2674). + +Почему обычной проверки уровня записи мало. В контейнере скрапера GlitchTip поднят +как `LoggingIntegration(level=INFO, event_level=ERROR)` (app/scheduler_main.py) — +значит WARNING остаётся строкой в docker-логе (которая теряется на редеплое) и +событием НЕ становится. Прод-цена этого: монитор устаревания СберИндекса отработал +24 раза, 9 из них со staleness-вердиктом — событий ноль; куки Домклика протухли +2026-08-03 — событий ноль. + +Поэтому здесь тесты проверяют ФАКТ СОБЫТИЯ, а не levelno: `glitchtip_events()` +поднимает настоящий sentry-клиент с той же интеграцией и тем же event_level, что в +проде, но с транспортом-списком. Если правку откатить (ERROR → WARNING), список +останется пустым и тест покраснеет. + +Оговорка, которую тесты проверить не могут: у GlitchTip-проекта сейчас нет ни правил, +ни получателей (#2673) — события будут видны в интерфейсе, но никому не отправятся. + +Без сети, без БД. +""" + +from __future__ import annotations + +import logging +import os +from collections.abc import Iterator +from contextlib import contextmanager +from datetime import UTC, date, datetime, timedelta +from typing import Any +from unittest.mock import AsyncMock, MagicMock, patch + +import httpx +import pytest +import sentry_sdk +from sentry_sdk.integrations.logging import LoggingIntegration + +os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:5432/test") + +from app.services import domclick_session as domclick_session_svc +from app.services import rosreestr_poll, sber_index +from app.tasks import deals_freshness_monitor as deals_mon +from app.tasks import domclick_detail_backfill as dc_backfill +from app.tasks import sber_freshness_monitor as sber_mon + +# ── харнесс: настоящий клиент GlitchTip с прод-настройками, транспорт — список ── + + +@contextmanager +def glitchtip_events() -> Iterator[list[dict[str, Any]]]: + """Собрать события так, как их увидел бы GlitchTip из контейнера скрапера. + + Интеграция и event_level — копия app/scheduler_main.py. Клиент ставится только + на время блока (isolation_scope), глобальное состояние не трогаем. + """ + events: list[dict[str, Any]] = [] + + def _collect(event: dict[str, Any], _hint: dict[str, Any]) -> None: + """before_send: событие уже собрано — записываем и НЕ отправляем (None).""" + events.append(event) + return None + + client = sentry_sdk.Client( + dsn="https://public@localhost/1", + before_send=_collect, + default_integrations=False, + integrations=[LoggingIntegration(level=logging.INFO, event_level=logging.ERROR)], + ) + with sentry_sdk.isolation_scope() as scope: + scope.set_client(client) + yield events + + +def event_texts(events: list[dict[str, Any]]) -> list[str]: + """Тексты событий — и логовых (logentry), и явных capture_message (message).""" + texts: list[str] = [] + for event in events: + entry = event.get("logentry") + if isinstance(entry, dict): + texts.append(str(entry.get("formatted") or entry.get("message") or "")) + elif isinstance(event.get("message"), str): + texts.append(event["message"]) + return texts + + +def test_harness_itself_drops_warnings() -> None: + """Мета-проверка харнесса: WARNING не событие, ERROR — событие. + + Без этого зелёные тесты ниже ничего не доказывали бы (пустой список мог бы быть + следствием сломанного харнесса, а не сломанного алерта). + """ + log = logging.getLogger("test_alerts_become_events.meta") + with glitchtip_events() as events: + log.warning("тихо") + log.error("громко") + assert event_texts(events) == ["громко"] + + +# ── 1. СберИндекс: монитор устаревания ──────────────────────────────────────── + + +class _FakeMonitorDB: + """Session-мок мониторов свежести: один SELECT max(...).""" + + def __init__(self, latest: date | None) -> None: + self._latest = latest + + def execute(self, stmt: Any, params: dict[str, Any] | None = None) -> Any: + result = MagicMock() + result.first.return_value = MagicMock(latest=self._latest) + return result + + def rollback(self) -> None: + pass + + +def _patch_runs(monkeypatch: pytest.MonkeyPatch, module: Any) -> None: + monkeypatch.setattr(module.runs_mod, "update_heartbeat", lambda *a, **k: None) + monkeypatch.setattr(module.runs_mod, "mark_done", lambda *a, **k: None) + monkeypatch.setattr(module.runs_mod, "mark_failed", lambda *a, **k: None) + + +def test_sber_staleness_becomes_event(monkeypatch: pytest.MonkeyPatch) -> None: + """Прод-состояние (9 срабатываний, ноль событий): застой бенчмарка → событие.""" + _patch_runs(monkeypatch, sber_mon) + db = _FakeMonitorDB(date(2026, 6, 1)) + with glitchtip_events() as events: + out = sber_mon.check_sber_freshness( + db, # type: ignore[arg-type] + run_id=1, + params={}, + now=datetime(2026, 8, 6, tzinfo=UTC), + ) + assert out["alert"] == 1 + assert any( + "sber freshness" in t for t in event_texts(events) + ), "устаревание СберИндекса не стало событием — WARNING до GlitchTip не долетает" + + +def test_sber_fresh_index_stays_silent(monkeypatch: pytest.MonkeyPatch) -> None: + """Свежие данные — ни одного события (иначе алерт-усталость).""" + _patch_runs(monkeypatch, sber_mon) + db = _FakeMonitorDB(date(2026, 6, 1)) + with glitchtip_events() as events: + out = sber_mon.check_sber_freshness( + db, # type: ignore[arg-type] + run_id=2, + params={}, + now=datetime(2026, 6, 20, tzinfo=UTC), + ) + assert out["alert"] == 0 + assert event_texts(events) == [] + + +def test_sber_empty_index_becomes_event(monkeypatch: pytest.MonkeyPatch) -> None: + """Бенчмарк пуст — монитор не может работать вовсе; mark_failed виден только стрику.""" + _patch_runs(monkeypatch, sber_mon) + db = _FakeMonitorDB(None) + with glitchtip_events() as events: + sber_mon.check_sber_freshness( + db, # type: ignore[arg-type] + run_id=3, + params={}, + now=datetime(2026, 8, 6, tzinfo=UTC), + ) + assert any("sber_price_index пуст" in t for t in event_texts(events)) + + +def test_deals_empty_becomes_event(monkeypatch: pytest.MonkeyPatch) -> None: + """Тот же класс у соседнего монитора сделок — найдено «шире» по #2674.""" + _patch_runs(monkeypatch, deals_mon) + db = _FakeMonitorDB(None) + with glitchtip_events() as events: + deals_mon.check_deals_freshness( + db, # type: ignore[arg-type] + run_id=4, + params={}, + now=datetime(2026, 8, 6, tzinfo=UTC), + ) + assert any("deals пуста" in t for t in event_texts(events)) + + +# ── 2. СберИндекс: 404 датасета (почему бенчмарк перестаёт обновляться) ──────── + + +async def test_sber_index_404_becomes_event() -> None: + """404 = переименованный slug: сбой ПЕРМАНЕНТНЫЙ, а был тише соседних 5xx-веток.""" + request = httpx.Request("GET", "https://sberindex.ru/api/sowa") + + def _raise_404(*args: Any, **kwargs: Any) -> Any: + raise httpx.HTTPStatusError( + "404", request=request, response=httpx.Response(404, request=request) + ) + + with ( + patch.object(sber_index, "fetch_sber_index", _raise_404), + glitchtip_events() as events, + ): + counters = await sber_index.pull_sber_indices( + MagicMock(), + cities={"66": "Свердловская область"}, + dashboards=[sber_index.SBER_DASHBOARDS[0]], + ) + + assert counters["errors"] == 1 + assert any("404 for dashboard" in t for t in event_texts(events)) + + +# ── 3. Куки Домклика: по факту и ЗАРАНЕЕ (образец — #2658 для Циана) ────────── + + +class _FakeDomclickDB: + """Session-мок: строка кук для session_expires_at + пустой снапшот листингов.""" + + def __init__(self, expires_at: datetime | None) -> None: + self._expires_at = expires_at + + def execute(self, stmt: Any, params: dict[str, Any] | None = None) -> Any: + result = MagicMock() + if "domclick_session_cookies" in str(stmt): + result.first.return_value = None if self._expires_at is None else (self._expires_at,) + else: + # snapshot листингов — пусто, прогон завершится до BrowserFetcher + result.mappings.return_value.all.return_value = [] + return result + + +async def _run_domclick( + monkeypatch: pytest.MonkeyPatch, + *, + cookies: dict[str, str] | None, + expires_at: datetime | None, +) -> list[str]: + _patch_runs(monkeypatch, dc_backfill) + monkeypatch.setattr(domclick_session_svc, "load_session", lambda _db: cookies) + db = _FakeDomclickDB(expires_at) + with glitchtip_events() as events: + await dc_backfill.run_domclick_detail_backfill( + db, # type: ignore[arg-type] + run_id=10, + params={}, + ) + return event_texts(events) + + +async def test_domclick_expired_cookies_become_event(monkeypatch: pytest.MonkeyPatch) -> None: + """Прод 2026-08-03: протухли, единственным следом был WARNING в docker-логе.""" + expired = datetime.now(tz=UTC) - timedelta(days=3) + texts = await _run_domclick(monkeypatch, cookies=None, expires_at=expired) + assert any("протухли" in t for t in texts), "протухшие куки не стали событием" + # Дата в тексте — чтобы оператор сразу видел, чинить сейчас или это давняя дыра. + assert any(expired.strftime("%Y-%m-%d") in t for t in texts) + + +async def test_domclick_missing_cookies_reason_differs(monkeypatch: pytest.MonkeyPatch) -> None: + """«Кук нет вовсе» и «протухли» лечатся одинаково, но диагностируются по-разному.""" + texts = await _run_domclick(monkeypatch, cookies=None, expires_at=None) + assert any("кук DomClick нет в БД" in t for t in texts) + + +async def test_domclick_warns_before_expiry(monkeypatch: pytest.MonkeyPatch) -> None: + """Предупреждение ЗАРАНЕЕ: куки ещё рабочие, но жить им меньше порога. + + Сигнал по факту протухания приходит, когда обогащение уже встало, а обновление + кук — ручная операция. По образцу #2658 (Циан). + """ + soon = datetime.now(tz=UTC) + timedelta(days=domclick_session_svc.COOKIE_EXPIRY_WARN_DAYS - 1) + texts = await _run_domclick(monkeypatch, cookies={"CAS_ID": "x"}, expires_at=soon) + assert any("протухнут" in t for t in texts), "не предупредили заранее" + + +async def test_domclick_fresh_cookies_are_silent(monkeypatch: pytest.MonkeyPatch) -> None: + """Свежие куки — ни одного события.""" + far = datetime.now(tz=UTC) + timedelta(days=25) + texts = await _run_domclick(monkeypatch, cookies={"CAS_ID": "x"}, expires_at=far) + assert texts == [] + + +def test_domclick_expiry_query_asks_for_the_used_row() -> None: + """valid_only=True — срок ИМЕННО той записи, которую взял бы load_session. + + При нескольких аккаунтах свежайшая-любая может быть чужой протухшей строкой. + """ + db = MagicMock() + db.execute.return_value.first.return_value = None + domclick_session_svc.session_expires_at(db, valid_only=True) + assert db.execute.call_args.args[1] == {"valid_only": True} + + +# ── 4. Поллер Росреестра: сбой каталога vs выход квартала ───────────────────── + + +def _client_returning(status_code: int) -> MagicMock: + client = MagicMock() + client.get = AsyncMock(return_value=httpx.Response(status_code, text="")) + return client + + +async def test_rosreestr_broken_index_becomes_event() -> None: + """Каталог не отдаёт 200 — поллер слеп. Портал уже один раз переезжал.""" + with glitchtip_events() as events: + available = await rosreestr_poll.check_new_quarter_available( + _client_returning(503), 2026, 3 + ) + assert available is False + assert any("unexpected HTTP 503" in t for t in event_texts(events)) + + +async def test_rosreestr_quarter_not_published_is_silent() -> None: + """Каталог жив, папки квартала ещё нет — самый частый прогон, событий быть не должно.""" + with glitchtip_events() as events: + available = await rosreestr_poll.check_new_quarter_available( + _client_returning(200), 2026, 3 + ) + assert available is False + assert event_texts(events) == [] + + +async def test_rosreestr_timeout_stays_out_of_events() -> None: + """Осознанно НЕ событие: транспортный блип раз в 28 дней сам пройдёт. + + «Квартал так и не приехал» ловит deals_freshness_monitor по max(deal_date). + """ + client = MagicMock() + client.get = AsyncMock(side_effect=httpx.TimeoutException("timeout")) + with glitchtip_events() as events: + await rosreestr_poll.check_new_quarter_available(client, 2026, 3) + assert event_texts(events) == [] + + +async def test_rosreestr_new_quarter_becomes_event() -> None: + """Хорошая новость — тоже событие: она требует ручного импорта оператором. + + Уровень info, а не error: событие в GlitchTip есть, а error-rate и стрик-алерты + не начинают врать про «сбой». INFO-строка в логе живёт до ближайшего редеплоя. + """ + with ( + patch.object(rosreestr_poll, "latest_loaded_quarter", MagicMock(return_value=(2026, 2))), + patch.object(rosreestr_poll, "check_new_quarter_available", AsyncMock(return_value=True)), + glitchtip_events() as events, + ): + out = await rosreestr_poll.poll_rosreestr_new_quarter(MagicMock()) + + assert out == { + "available": True, + "year": 2026, + "quarter": 3, + "latest_loaded_year": 2026, + "latest_loaded_quarter": 2, + } + assert any("доступен новый квартал Q3 2026" in t for t in event_texts(events)) diff --git a/tradein-mvp/backend/tests/test_sber_index.py b/tradein-mvp/backend/tests/test_sber_index.py index ed31e11c..61b7f1c7 100644 --- a/tradein-mvp/backend/tests/test_sber_index.py +++ b/tradein-mvp/backend/tests/test_sber_index.py @@ -469,10 +469,15 @@ async def test_pull_sber_indices_error_per_series_continues() -> None: @pytest.mark.asyncio -async def test_pull_sber_indices_404_logs_warning_with_path_hint( +async def test_pull_sber_indices_404_logs_error_with_path_hint( caplog: pytest.LogCaptureFixture, ) -> None: - """#902: a 404 logs a WARNING naming the slug + 'dataset-path invalid?' hint.""" + """#902: a 404 logs the slug + 'dataset-path invalid?' hint. + + #2674: уровень поднят WARNING → ERROR. 404 = переименованный slug, самая + ПЕРМАНЕНТНАЯ из трёх веток отказа (5xx и сетевой сбой проходят сами), а до этого + она была тише соседних и событием GlitchTip не становилась. + """ import logging import httpx @@ -498,11 +503,11 @@ async def test_pull_sber_indices_404_logs_warning_with_path_hint( ) assert result["errors"] == 1 - warnings = [r for r in caplog.records if r.levelno == logging.WARNING] + errors = [r for r in caplog.records if r.levelno >= logging.ERROR] assert any( "residential_real_estate_prices" in r.message and "dataset-path invalid" in r.message - for r in warnings - ), f"Expected a 404 dataset-path warning, got: {[r.message for r in warnings]}" + for r in errors + ), f"Expected a 404 dataset-path ERROR, got: {[r.message for r in errors]}" @pytest.mark.asyncio -- 2.45.3 From 3e1b9a8b0de94dbf526dbaefcf2a2b3a8ab073b8 Mon Sep 17 00:00:00 2001 From: bot-backend Date: Thu, 6 Aug 2026 02:53:26 +0500 Subject: [PATCH 2/2] =?UTF-8?q?fix(tradein):=20=D1=87=D0=B8=D0=BD=D0=B8?= =?UTF-8?q?=D1=82=20=D1=82=D0=B0=D0=BA=D1=82=20=D0=B7=D0=B0=D0=B3=D1=80?= =?UTF-8?q?=D1=83=D0=B7=D0=BA=D0=B8=20=D0=A1=D0=B1=D0=B5=D1=80=D0=98=D0=BD?= =?UTF-8?q?=D0=B4=D0=B5=D0=BA=D1=81=D0=B0=20=E2=80=94=20=D0=B8=D0=BD=D0=B0?= =?UTF-8?q?=D1=87=D0=B5=20=D0=BD=D0=BE=D0=B2=D1=8B=D0=B9=20ERROR=20=D1=81?= =?UTF-8?q?=D1=82=D0=B0=D0=BB=20=D0=B1=D1=8B=20=D0=BB=D0=BE=D0=B6=D0=BD?= =?UTF-8?q?=D0=BE=D0=B9=20=D1=82=D1=80=D0=B5=D0=B2=D0=BE=D0=B3=D0=BE=D0=B9?= =?UTF-8?q?=20(#2674)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Ревью PR #2681 опровергло исходную посылку по СберИндексу, и это подтвердилось на моих же числах (все 24 прогона монитора, read-only): 13-16.07 alert=1 age 73..76 latest=май 17.07 alert=0 age 46 latest=июнь ← день загрузки 18-31.07 alert=0 age 47..60 01-05.08 alert=1 age 61..65 Загрузка ходила раз в 28 дней и приносила период на месяц новее, возраст считается от первого числа покрытого месяца → пол 46, потолок 74, порог 60 ВНУТРИ диапазона. Тревога срабатывала 14 суток из 28 без всякого застоя источника: девять срабатываний были замером нашего собственного такта. Поднятие до ERROR без этой правки завело бы ежедневное ложное событие две недели в месяц. Миграция 212 переводит sber_index_pull на недельный такт (потолок ≈53 при пороге 60, запас 7 суток) вместо поднятия порога до 75 (запас 1 сутки — ломается от любого сдвига окна). Цена: 9 запросов в неделю вместо 9 в 28 дней к публичному sberindex.ru/api/sowa; прогон 4 секунды, 0 ошибок за всю историю. Дополнительно по ревью: - поллер Росреестра: ветка «файл найден в листинге, но HEAD не отдал zip» → ERROR (ровно поведение старой Bitrix-заглушки) + вписана в таблицу уровней; - тестовый харнесс закрывает клиент событий (фоновый поток на каждый тест). Refs #2674 --- .../backend/app/services/rosreestr_poll.py | 13 +++- .../app/tasks/sber_freshness_monitor.py | 33 ++++++--- .../data/sql/212_sber_index_pull_weekly.sql | 68 +++++++++++++++++++ .../tests/test_alerts_become_events.py | 32 ++++++++- .../tests/test_sber_freshness_monitor.py | 35 ++++++++++ 5 files changed, 169 insertions(+), 12 deletions(-) create mode 100644 tradein-mvp/backend/data/sql/212_sber_index_pull_weekly.sql diff --git a/tradein-mvp/backend/app/services/rosreestr_poll.py b/tradein-mvp/backend/app/services/rosreestr_poll.py index 3fa293b0..3d278acd 100644 --- a/tradein-mvp/backend/app/services/rosreestr_poll.py +++ b/tradein-mvp/backend/app/services/rosreestr_poll.py @@ -55,6 +55,11 @@ sber_index.py для sberindex.ru (см. #922, тот же паттерн: пу - Портал ответил не-200 на листинг каталога/папки → ERROR. Каталог — единственная опора поллера; портал УЖЕ один раз переехал (см. "ИСТОРИЯ"), и тогда поллер молча врал целыми кварталами. Такое обязано быть событием. + - Файл датасета НАЙДЕН в листинге, но HEAD не отдал zip / размер ниже порога → + ERROR. Тот же класс: это ровно поведение старой Bitrix-заглушки (200 + text/html). + Ветка может сработать легитимно (файл выложили в листинг раньше, чем докачали), + но цена асимметрична — ложное срабатывание стоит одного события в месяц (такт + 28 дней), пропуск стоит квартала молчания. - Таймаут / сетевая ошибка → WARNING, как раньше. Это транспортный блип раз в месяц (такт поллера), сам пройдёт; а «квартал так и не приехал» ловит отдельный deals_freshness_monitor ERROR-ом по max(deal_date). @@ -322,7 +327,13 @@ async def check_new_quarter_available( ) return True - logger.info( + # ERROR (#2674, ревью PR #2681): файл ЕСТЬ в листинге, но HEAD отдал не zip + # либо размер ниже порога — это буквально тот сбой, из-за которого поллер уже + # врал (Bitrix-заглушка отвечала 200 с text/html вместо архива, см. "ИСТОРИЯ"). + # Ветка может сработать и легитимно — файл появился в листинге раньше, чем + # докачался, — но цена асимметрична: такт 28 дней, значит ложное срабатывание + # стоит максимум одного события в месяц, а пропуск стоит квартала молчания. + logger.error( "rosreestr_poll: Q%d %d file found (%s) but failed availability check " "(HTTP %d, Content-Type=%r, Content-Length=%d) — soft-404 guard, " "treating as unavailable", diff --git a/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py b/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py index 22193491..487179d5 100644 --- a/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py +++ b/tradein-mvp/backend/app/tasks/sber_freshness_monitor.py @@ -14,21 +14,34 @@ #2674 — почему ERROR, а не WARNING. В контейнере скрапера GlitchTip поднят с LoggingIntegration(event_level=ERROR) (scheduler_main.py), поэтому WARNING -событием НЕ становится: на проде монитор отработал 24 раза, из них 9 со -staleness-вердиктом — и ни одного события. Бенчмарк цен участвует в сверке наших -медиан, его застой — сбой, а не наблюдение. Сосед по конструкции -(deals_freshness_monitor) писал ERROR с самого начала — расходилась только эта -джоба. +событием НЕ становится вообще. Бенчмарк цен участвует в сверке наших медиан, его +застой — сбой, а не наблюдение. Сосед по конструкции (deals_freshness_monitor) +писал ERROR с самого начала — расходилась только эта джоба. + +ВАЖНО про «9 срабатываний» из #2674 (ревью PR #2681, прод-разбор всех 24 прогонов +монитора 2026-08-06). Эти девять НЕ были застоем бенчмарка — это была ПИЛА нашего +собственного такта загрузки: + 13-16.07 alert=1 age 73..76 latest=май 01-05.08 alert=1 age 61..65 + 17.07 alert=0 age 46 latest=июнь (день загрузки) +Загрузка ходила раз в 28 дней и приносила период на месяц новее, возраст же +считается от ПЕРВОГО числа покрытого месяца → пол ~46 в момент загрузки, потолок +46+28=74, порог 60 ВНУТРИ диапазона, тревога 14 суток из 28 каждый цикл. Поднимать +такое до ERROR без починки такта значило бы завести ежедневное ложное событие на +две недели в месяц. Поэтому миграция 212 перевела sber_index_pull на НЕДЕЛЬНЫЙ +такт: потолок возраста ≈ пол+7 ≈ 53 при пороге 60, тревога снова означает +«источник/загрузка встали», а не «мы давно не ходили». Порог алерта (документирование выбора): Per-estimate guard (estimator): age > settings.sber_index_max_age_days (35д). Монитор: age > sber_index_max_age_days + lag_allowance. lag_allowance (DEFAULT_LAG_ALLOWANCE_DAYS=25) — запас на ИНХЕРЕНТНЫЙ лаг - публикации СберИндекса: источник отстаёт на 1-2 месяца, period_month — лейбл - ПЕРВОГО числа месяца, а месячный pull ещё не подтянул новейший период. Итог: - 35 + 25 = 60д. Ниже 60д latest считается «нормально отстающим» → алерта нет - (иначе daily-шум на штатном лаге). Выше 60д данные застряли сверх ~2 месяцев - → алерт. Проверено на проде 2026-07-12: max=2026-05-01, age=72д > 60 → alert=1. + публикации СберИндекса: источник отстаёт на 1-2 месяца, а period_month — лейбл + ПЕРВОГО числа месяца, поэтому даже свежайшая загрузка даёт возраст ~46 суток. + Итог: 35 + 25 = 60д. При недельном такте (миграция 212) рабочий диапазон возраста + ~46..53 — до порога остаётся ~7 суток запаса: один пропущенный недельный цикл + поглощается, два подряд дают тревогу. Порог НЕ должен снова оказаться внутри + рабочего диапазона — если такт загрузки будут менять, пересчитай потолок + (пол + interval_days) и сверь с 60. Задача синхронная (DB-only, один SELECT max(period_month)) — запускается kit-scheduler'ом через product_handlers._job_sber_freshness_monitor в diff --git a/tradein-mvp/backend/data/sql/212_sber_index_pull_weekly.sql b/tradein-mvp/backend/data/sql/212_sber_index_pull_weekly.sql new file mode 100644 index 00000000..07aaea2e --- /dev/null +++ b/tradein-mvp/backend/data/sql/212_sber_index_pull_weekly.sql @@ -0,0 +1,68 @@ +-- 212_sber_index_pull_weekly.sql +-- sber_index_pull: такт 28 дней → 7. Ревью PR #2681 (#2674). +-- +-- ПОЧЕМУ. Монитор sber_freshness_monitor алертил при age > 60д +-- (sber_index_max_age_days 35 + lag_allowance 25). Прод-разбор всех 24 прогонов +-- монитора (read-only, 2026-08-06, scrape_runs.counters) показал ПИЛУ, а не застой: +-- +-- 13-16.07 alert=1 age 73,74,75,76 latest_month=5 (май) +-- 17.07 alert=0 age 46 latest_month=6 ← день загрузки +-- 18-31.07 alert=0 age 47..60 latest_month=6 +-- 01-05.08 alert=1 age 61..65 latest_month=6 +-- +-- Механика: загрузка ходила раз в 28 дней и приносила период на месяц новее, а +-- возраст считается от ПЕРВОГО ЧИСЛА покрытого месяца. Значит в момент самой +-- свежей загрузки возраст уже ~46 (07-17 минус 06-01), к следующей дорастает до +-- 46+28=74, и порог 60 лежит ВНУТРИ [46, 74] — тревога пересекала его каждый +-- цикл, 14 суток из 28. Девять срабатываний, поданных в #2674 как улика застоя +-- бенчмарка, — это замер НАШЕГО СОБСТВЕННОГО ТАКТА. После #2681 (WARNING → ERROR) +-- это стало бы ежедневным событием две недели в месяц, гаснущим само собой — +-- ровно та ложная тревога, которая приучает не читать алерты. +-- +-- ПОЧЕМУ ТАКТ, А НЕ ПОРОГ. Рассматривались два варианта: +-- (A) поднять lag_allowance 25 → 40 (порог 75 против потолка 74). Запас ОДИН +-- день: любой сдвиг окна/пропуск прогона на сутки — и ложная тревога +-- возвращается. Порог при этом продолжает кодировать наш такт, а не +-- поведение источника. Отклонено. +-- (B) ЭТА миграция: такт 28 → 7. Потолок возраста становится floor+7 ≈ 53 при +-- том же пороге 60 — запас 7 суток, т.е. один пропущенный недельный цикл +-- поглощается, два подряд дают тревогу (и это уже осмысленная тревога). +-- Порог 60 начинает означать ИМЕННО «Сбер перестал публиковать / загрузка +-- сломалась», а не «мы давно не ходили». +-- +-- ЦЕНА. pull_sber_indices делает SBER_REF_AREAS (3: 643/66/77) × SBER_DASHBOARDS +-- (3) = 9 GET-запросов к публичному неавторизованному sberindex.ru/api/sowa, без +-- пауз в цикле; прод-прогон 2026-07-17 занял 4 секунды (counters.duration_sec=4, +-- errors=0, upserted=639). Было 9 запросов / 28 дней, стало 9 / 7 дней = 36 в +-- месяц. Это тот же эндпоинт, который дёргают сами дашборды Сбера при каждом +-- открытии страницы; лимитов/бана на нём за всю историю прогонов не наблюдалось +-- (0 ошибок в 6 прогонах). Риск нагрузки считаем отсутствующим. +-- +-- ПОБОЧНО. Оценщик имеет СВОЙ per-estimate guard свежести с порогом +-- settings.sber_index_max_age_days=35. Он пробивается всегда, потому что возраст +-- стартует с ~46. Недельный такт сокращает НАШУ задержку обнаружения с ≤28 суток +-- до ≤7, то есть возраст = (лаг публикации Сбера) + ≤7 вместо + ≤28. Уйдёт ли он +-- под 35 — зависит от того, когда Сбер реально публикует месяц (по нашим данным +-- лаг публикации ≤46 и ≥31 суток, точнее по имеющимся прогонам не определить), +-- поэтому НЕ обещаем починку этого guard'а, только снятие нашей части задержки. +-- +-- next_run_at подтягиваем на ближайшее окно (05:00-06:00 UTC): без этого правка +-- default_params начнёт действовать только после уже запланированного прогона +-- 2026-08-14, а до тех пор ложная тревога продолжала бы идти каждый день. +-- LEAST() — чтобы повторное применение НИКОГДА не отодвигало прогон дальше. +-- +-- Идемпотентно: jsonb-конкатенация + LEAST, повторный прогон безопасен. +-- Кода не меняет: interval_days читается kit-планировщиком из default_params +-- (orchestration/scheduler.py::_defer_next_run_at, params.get("interval_days", 1)). + +BEGIN; + +UPDATE scrape_schedules +SET default_params = COALESCE(default_params, '{}'::jsonb) || '{"interval_days": 7}'::jsonb, + next_run_at = LEAST( + next_run_at, + ((CURRENT_DATE + INTERVAL '1 day') + make_interval(hours => 5)) AT TIME ZONE 'UTC' + ) +WHERE source = 'sber_index_pull'; + +COMMIT; diff --git a/tradein-mvp/backend/tests/test_alerts_become_events.py b/tradein-mvp/backend/tests/test_alerts_become_events.py index a58d5910..ae084d93 100644 --- a/tradein-mvp/backend/tests/test_alerts_become_events.py +++ b/tradein-mvp/backend/tests/test_alerts_become_events.py @@ -66,7 +66,11 @@ def glitchtip_events() -> Iterator[list[dict[str, Any]]]: ) with sentry_sdk.isolation_scope() as scope: scope.set_client(client) - yield events + try: + yield events + finally: + # Иначе на каждый тест остаётся фоновый поток транспорта. + client.close() def event_texts(events: list[dict[str, Any]]) -> list[str]: @@ -304,6 +308,32 @@ async def test_rosreestr_broken_index_becomes_event() -> None: assert any("unexpected HTTP 503" in t for t in event_texts(events)) +async def test_rosreestr_stub_instead_of_zip_becomes_event() -> None: + """Файл есть в листинге, но HEAD отдал заглушку — тот сбой, из-за которого уже врали. + + Ровно поведение старой Bitrix-заглушки: HTTP 200 + text/html вместо архива. + """ + index_html = 'q' + folder_html = 'f' + client = MagicMock() + client.get = AsyncMock( + side_effect=[ + httpx.Response(200, text=index_html), + httpx.Response(200, text=folder_html), + ] + ) + client.head = AsyncMock( + return_value=httpx.Response( + 200, text="stub", headers={"content-type": "text/html", "content-length": "512"} + ) + ) + with glitchtip_events() as events: + available = await rosreestr_poll.check_new_quarter_available(client, 2026, 3) + + assert available is False + assert any("soft-404 guard" in t for t in event_texts(events)) + + async def test_rosreestr_quarter_not_published_is_silent() -> None: """Каталог жив, папки квартала ещё нет — самый частый прогон, событий быть не должно.""" with glitchtip_events() as events: diff --git a/tradein-mvp/backend/tests/test_sber_freshness_monitor.py b/tradein-mvp/backend/tests/test_sber_freshness_monitor.py index 114322af..726d991e 100644 --- a/tradein-mvp/backend/tests/test_sber_freshness_monitor.py +++ b/tradein-mvp/backend/tests/test_sber_freshness_monitor.py @@ -28,6 +28,7 @@ from app.tasks import sber_freshness_monitor as mon _SQL_DIR = Path(__file__).resolve().parents[1] / "data" / "sql" _MIGRATION_180 = _SQL_DIR / "180_seed_sber_freshness_monitor.sql" +_MIGRATION_212 = _SQL_DIR / "212_sber_index_pull_weekly.sql" # max(period_month) вторичного сегмента = 2026-05-01 (проверено на проде 2026-07-12). _MAY_2026 = date(2026, 5, 1) @@ -218,6 +219,40 @@ def test_migration_180_no_psycopg_trap() -> None: assert not re.search(r":\w+::", sql) +# ── Миграция 212: такт загрузки не должен пересекать порог монитора ─────────── +# +# Прод-разбор (ревью PR #2681): загрузка раз в 28 дней давала возраст-пилу 46..74 +# при пороге 60 — тревога срабатывала 14 суток из 28 БЕЗ всякого застоя источника. +# Тест держит инвариант: потолок возраста (пол + такт загрузки) < порога монитора. + + +def test_migration_212_makes_pull_cadence_weekly() -> None: + sql = _MIGRATION_212.read_text("utf-8") + assert "sber_index_pull" in sql + assert '"interval_days": 7' in sql + assert "BEGIN;" in sql and "COMMIT;" in sql + assert not re.search(r":\w+::", sql) # psycopg v3: только CAST(:x AS type) + + +def test_pull_cadence_leaves_margin_under_monitor_threshold() -> None: + """Инвариант: пол возраста + такт загрузки < порога монитора. + + Пол = 46 суток (прод 2026-07-17: загрузка принесла 2026-06-01). Порог = + sber_index_max_age_days + lag_allowance. При такте 7: 46+7=53 < 60 — запас + 7 суток. При прежних 28: 46+28=74 > 60 — тревога каждый цикл, что и наблюдали. + """ + interval_days = int( + re.search(r'"interval_days":\s*(\d+)', _MIGRATION_212.read_text("utf-8")).group(1) + ) + observed_floor_days = 46 + threshold = settings.sber_index_max_age_days + mon.DEFAULT_LAG_ALLOWANCE_DAYS + assert observed_floor_days + interval_days < threshold, ( + f"такт {interval_days}д даёт потолок возраста " + f"{observed_floor_days + interval_days}д при пороге {threshold}д — " + "монитор снова будет мерить наш такт, а не застой источника" + ) + + # ── Регистрация в kit registry ───────────────────────────────────────────────── -- 2.45.3