fix(tradein): сигналы о сбоях наконец становятся событиями, а протухание кук предупреждает заранее (#2674)
All checks were successful
CI Trade-In / changes (pull_request) Successful in 7s
CI / changes (pull_request) Successful in 8s
CI Trade-In / frontend-checks (pull_request) Has been skipped
CI / backend-tests (pull_request) Has been skipped
CI / frontend-tests (pull_request) Has been skipped
CI / openapi-codegen-check (pull_request) Has been skipped
CI Trade-In / backend-tests (pull_request) Successful in 2m58s

В скрапер-контейнере 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
This commit is contained in:
bot-backend 2026-08-06 02:29:11 +05:00
parent 9f9086fa4d
commit 46bbb79881
9 changed files with 565 additions and 51 deletions

View file

@ -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(

View file

@ -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,

View file

@ -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/<slug> via dashboard route-interception)",

View file

@ -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)

View file

@ -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)

View file

@ -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 ДКП-сделок мог отстать — "

View file

@ -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),

View file

@ -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))

View file

@ -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