diff --git a/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py b/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py index da802ffe..c65fdd7d 100644 --- a/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py +++ b/tradein-mvp/backend/app/tasks/domclick_detail_backfill.py @@ -90,9 +90,11 @@ from collections import Counter from dataclasses import dataclass, field from datetime import UTC, datetime, timedelta +import httpx from scraper_kit.browser_fetcher import BrowserFetcher, ban_kind_from_status from scraper_kit.domclick_exceptions import DomClickBlockedError, DomClickParseError from scraper_kit.providers.domclick.detail import fetch_detail, save_detail_enrichment +from scraper_kit.proxy_errors import NoProxyAvailableError from sqlalchemy import text from sqlalchemy.orm import Session @@ -182,6 +184,49 @@ def _warn_before_domclick_cookies_expire(db: Session, run_id: int) -> None: _DOMCLICK_REFUSAL_STATUSES = frozenset({401}) +def _iter_causes(exc: BaseException) -> list[BaseException]: + """Цепочка причин исключения, без зацикливания.""" + seen: set[int] = set() + out: list[BaseException] = [] + cur: BaseException | None = exc + while cur is not None and id(cur) not in seen: + out.append(cur) + seen.add(id(cur)) + cur = cur.__cause__ or cur.__context__ + return out + + +def _caused_by_empty_pool(exc: BaseException) -> bool: + """Прячется ли за этим «блоком» пустой пул прокси (#3283). + + `NoProxyAvailableError` документирован ровно как «НАША инфраструктура, не + внешний блок», и поднимается ДО HTTP-запроса: к площадке мы не ходили вовсе. + Сюда он попадает под видом блокировки, потому что `fetch_detail` заворачивает + в `DomClickBlockedError` любое исключение фетча (`except Exception`). + """ + return any(isinstance(c, NoProxyAvailableError) for c in _iter_causes(exc)) + + +def _is_transport_failure(exc: BaseException) -> bool: + """Сбой нашей стороны, а не отказ площадки (#3283). + + Различать по HTTP-статусу нельзя: настоящий QRATOR-челлендж приходит вообще + без статуса либо под 200, то есть неотличим от таймаута навигации. Зато + различима ПРИРОДА исключения, и разделение уже проведено в `fetch_detail`: + + * ветка `except SidecarBanPageError` — сайдкар опознал страницу-отказ по + маркерам тела, это генуинный бан (там же `report_ban`); + * `parse_detail_html`, поднявший `DomClickBlockedError` — маркеры в HTML, + тоже генуинный; + * ветка `except Exception` — таймаут / 5xx сайдкара / транспорт, обёрнутый + `raise ... from exc`. Исходное исключение остаётся в `__cause__`. + + Смотрим именно на третий случай: httpx-ошибка в цепочке причин. Отсутствие + статуса признаком служить не может — им как раз отличается генуинный блок. + """ + return any(isinstance(c, httpx.HTTPError) for c in _iter_causes(exc)) + + def _ban_kind_of_block(exc: DomClickBlockedError) -> str: """Диагноз одного блока по HTTP-статусу ответа площадки (#3196, #3178). @@ -241,6 +286,10 @@ async def run_domclick_detail_backfill( budget_sec = float(params.get("budget_sec", 3600)) request_delay_sec = float(params.get("request_delay_sec", 12.0)) max_consecutive_blocks = int(params.get("max_consecutive_blocks", 3)) + # #3283: отдельный, намеренно более высокий порог для сбоев нашей стороны + # (таймаут навигации, 5xx сайдкара). Тройка на них — хайртриггер: прогон 5399 + # умер на трёх подряд, не увидев ни одного отказа площадки. + max_consecutive_soft = int(params.get("max_consecutive_soft_failures", 10)) counters = DomClickDetailBackfillResult() current_counters: dict[str, int] = counters.to_dict() @@ -305,6 +354,9 @@ async def run_domclick_detail_backfill( ) consecutive_blocks = 0 + # #3283: сбои НЕ блочной природы считаются отдельно и с большим порогом. + consecutive_soft = 0 + no_proxy_stop = False # #3212: сброс переиспользуемого context'а разрешён РОВНО ОДИН раз за прогон. # Причина ниже, у самого вызова request_context_reset. context_reset_used = False @@ -385,6 +437,7 @@ async def run_domclick_detail_backfill( if save_detail_enrichment(db, listing_id, enrichment): counters.enriched += 1 consecutive_blocks = 0 + consecutive_soft = 0 except DomClickParseError as e: # Schema drift, not a block -- neutral to the block-breaker (does @@ -399,9 +452,67 @@ async def run_domclick_detail_backfill( ) except DomClickBlockedError as e: + ban_kind = _ban_kind_of_block(e) + + # #3283 (1): пустой пул — не блок. Запрос к площадке НЕ уходил, + # и следующая карточка упрётся ровно в то же самое: продолжать + # цикл бессмысленно, а начислять блок — прямая ложь про причину. + # Прогон 5399 умер именно так: три «блока» подряд, из них два + # 500 от сайдкара и один пустой пул, отказов площадки — ноль. + if _caused_by_empty_pool(e): + logger.error( + "domclick_detail_backfill: run_id=%d СТОП — пул прокси пуст, " + "к площадке не ходили. enriched=%d attempted=%d", + run_id, + counters.enriched, + counters.attempted, + ) + no_proxy_stop = True + break + + # #3283 (2): порог считаем по ПРИЧИНЕ, а не по числу исключений. + # Обрыв нужен, чтобы не долбить отказывающую площадку, — значит + # считать надо её отказы. Таймаут навигации и 5xx сайдкара это + # наша сторона; они идут в failed, как уже идёт DomClickParseError + # (он честно помечен «schema drift, not a block»). + if _is_transport_failure(e): + counters.failed += 1 + consecutive_soft += 1 + block_ban_kinds[ban_kind] += 1 + logger.warning( + "domclick_detail_backfill: run_id=%d СБОЙ #%d/%d " + "(подряд=%d/%d, http=%s, kind=%s, не блок площадки): %s", + run_id, + idx + 1, + len(snapshot), + consecutive_soft, + max_consecutive_soft, + getattr(e, "status", None), + ban_kind, + e, + ) + # Сторож на случай, если площадка отказывает молча (сайдкар не + # отдал статус → kind='unknown'): без него такой отказ гнал бы + # весь батч впустую. Порог выше блочного намеренно — цена + # ошибки здесь несимметрична, см. #3272. + if consecutive_soft >= max_consecutive_soft: + logger.error( + "domclick_detail_backfill: run_id=%d ABORT -- %d сбоев " + "подряд без единого отказа площадки, диагнозы: %s. " + "enriched=%d attempted=%d", + run_id, + consecutive_soft, + dict(block_ban_kinds) or "нет", + counters.enriched, + counters.attempted, + ) + aborted_by_blocks = True + break + # Пауза не нужна: цикл сам спит в начале следующей итерации. + continue + consecutive_blocks += 1 counters.blocked += 1 - ban_kind = _ban_kind_of_block(e) block_ban_kinds[ban_kind] += 1 # #3118 просил сброс на КАЖДЫЙ блок — и этим сам себя блокировал. # Пропуск QRATOR (куки qrator_jsid2 + qrator_jsr) живёт в context'е; @@ -459,14 +570,26 @@ async def run_domclick_detail_backfill( counters.duration_sec = time.monotonic() - start current_counters = counters.to_dict() - runs_mod.mark_backfill_finished( - db, - run_id, - current_counters, - source="domclick_detail_backfill", - aborted_by_blocks=aborted_by_blocks, - ban_kinds=block_ban_kinds, - ) + if no_proxy_stop: + # #3283: остановка из-за пустого пула — НЕ блок, поэтому и не + # aborted_by_blocks: иначе прогон уйдёт в 'banned' и запись будет + # утверждать про площадку то, чего не было. Это отказ нашей стороны. + current_counters["no_proxy_stop"] = 1 + runs_mod.mark_failed( + db, + run_id, + "пул прокси пуст — к площадке не ходили (#3283)", + current_counters, + ) + else: + runs_mod.mark_backfill_finished( + db, + run_id, + current_counters, + source="domclick_detail_backfill", + aborted_by_blocks=aborted_by_blocks, + ban_kinds=block_ban_kinds, + ) logger.info( "domclick_detail_backfill: run_id=%d FINISHED -- attempted=%d enriched=%d " "blocked=%d failed=%d duration=%.1fs", diff --git a/tradein-mvp/backend/tests/tasks/test_3283_non_blocks_counted_as_blocks.py b/tradein-mvp/backend/tests/tasks/test_3283_non_blocks_counted_as_blocks.py new file mode 100644 index 00000000..b0881130 --- /dev/null +++ b/tradein-mvp/backend/tests/tasks/test_3283_non_blocks_counted_as_blocks.py @@ -0,0 +1,204 @@ +"""#3283: сбои нашей стороны считались отказами площадки и втроём рвали добор. + +Прогон 5399 (30.08) умер по правилу «3 блока подряд», не обогатив ни одной карточки. +Из трёх засчитанных блоков отказом Домклика не был НИ ОДИН: два — HTTP 500 от сайдкара +(таймаут навигации), третий — пустой пул прокси, при котором запрос к площадке вообще +не отправлялся. Лог абортa сам это печатал: `диагнозы: {'unknown': 3}`. + +Различать по HTTP-статусу нельзя — настоящий QRATOR-челлендж приходит без статуса и +неотличим от таймаута. Различима природа исключения: транспортные сбои приезжают +обёрнутыми вокруг httpx-ошибки (`except Exception` в fetch_detail делает +`raise DomClickBlockedError(...) from exc`), генуинные блоки — нет. +""" + +from __future__ import annotations + +import os +import sys +from unittest.mock import AsyncMock, MagicMock, patch + +os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:5432/test") + +_wp_mock = MagicMock() +sys.modules.setdefault("weasyprint", _wp_mock) + +import httpx # noqa: E402 +import pytest # noqa: E402 +from scraper_kit.domclick_exceptions import DomClickBlockedError # noqa: E402 +from scraper_kit.proxy_errors import NoProxyAvailableError # noqa: E402 + +from app.core import shutdown as _sd # noqa: E402 +from app.tasks.domclick_detail_backfill import run_domclick_detail_backfill # noqa: E402 + +from .test_domclick_detail_backfill import ( # noqa: E402 + _BROWSER_FETCHER, + _FETCH, + _RUNS, + _SAVE, + _SESSION_SVC, + _SETTINGS, + _SLEEP, + _make_snapshot, + _mock_browser_fetcher_cls, + _mock_db, + _mock_session_svc, +) + + +@pytest.fixture(autouse=True) +def _reset_shutdown() -> None: + _sd.reset_shutdown() + yield + _sd.reset_shutdown() + + +# ── как выглядят три природы отказа ────────────────────────────────────────── + + +def _sidecar_500() -> DomClickBlockedError: + """Ровно то, что валило прогон 5399: 500 от сайдкара, обёрнутый в «блок».""" + transport = httpx.HTTPStatusError( + "Server error '500 Internal Server Error'", + request=httpx.Request("POST", "http://tradein-browser:3000/fetch"), + response=httpx.Response(500), + ) + exc = DomClickBlockedError("DomClick detail browser fetch failed: 500") + exc.__cause__ = transport + return exc + + +def _empty_pool() -> DomClickBlockedError: + exc = DomClickBlockedError("DomClick detail browser fetch failed: no proxy") + exc.__cause__ = NoProxyAvailableError("domclick") + return exc + + +def _genuine_block() -> DomClickBlockedError: + """Маркеры QRATOR в теле: причины-обёртки нет, статуса тоже может не быть.""" + return DomClickBlockedError("QRATOR challenge page detected") + + +async def _run(side_effect, *, n: int = 10, **params): + db = _mock_db(_make_snapshot(n)) + runs = MagicMock() + with ( + patch(_SETTINGS, MagicMock(browser_http_endpoint="http://browser:9000")), + patch(_SESSION_SVC, _mock_session_svc({"CAS_ID": "123"})), + patch(_RUNS, runs), + patch(_BROWSER_FETCHER, _mock_browser_fetcher_cls()), + patch(_FETCH, AsyncMock(side_effect=side_effect)), + patch(_SAVE, MagicMock(return_value=True)), + patch(_SLEEP, new_callable=AsyncMock), + ): + result = await run_domclick_detail_backfill( + db, run_id=1, params={"batch_size": n, "budget_sec": 3600, **params} + ) + return result, runs + + +# ── пустой пул ─────────────────────────────────────────────────────────────── + + +async def test_empty_pool_stops_immediately_without_counting_a_block() -> None: + """Пул пуст → остановка на первой же карточке, блоков ноль. + + Продолжать цикл бессмысленно: каждая следующая упрётся в то же самое. + """ + result, _ = await _run(_empty_pool()) + assert result.attempted == 1 + assert result.blocked == 0 + + +async def test_empty_pool_is_not_reported_as_a_platform_ban() -> None: + """Прогон уходит в failed, а не в banned: запись не должна утверждать про + площадку то, чего не было — к ней не ходили.""" + _, runs = await _run(_empty_pool()) + runs.mark_failed.assert_called_once() + runs.mark_backfill_finished.assert_not_called() + assert "#3283" in runs.mark_failed.call_args.args[2] + + +# ── транспортные сбои ──────────────────────────────────────────────────────── + + +async def test_three_sidecar_500s_no_longer_abort_the_run() -> None: + """Ровно сценарий 5399: три 500 подряд больше не рвут прогон. + + Порог существует, чтобы не долбить ОТКАЗЫВАЮЩУЮ площадку. Три таймаута + сайдкара про площадку не говорят ничего. + """ + result, _ = await _run( + [_sidecar_500(), _sidecar_500(), _sidecar_500(), None, None, None, None, None, None, None], + n=10, + ) + assert result.attempted == 10, "прогон обязан дойти до конца батча" + assert result.blocked == 0 + + +async def test_sidecar_500_counts_as_failure_not_block() -> None: + """Транспорт идёт в failed — туда же, куда давно идёт DomClickParseError.""" + result, _ = await _run([_sidecar_500()] + [None] * 4, n=5) + assert result.failed == 1 + assert result.blocked == 0 + assert result.enriched == 4 + + +async def test_run_recovers_after_transport_failures() -> None: + """Сбой не должен отравлять остаток батча: следующие карточки обогащаются.""" + result, _ = await _run([_sidecar_500(), None, _sidecar_500(), None, None], n=5) + assert result.enriched == 3 + assert result.failed == 2 + + +# ── генуинный блок по-прежнему рвёт прогон ─────────────────────────────────── + + +async def test_genuine_blocks_still_abort_after_threshold() -> None: + """Главная страховка правки: настоящие отказы площадки считаются как раньше.""" + result, runs = await _run([_genuine_block()] * 10, n=10, max_consecutive_blocks=3) + assert result.blocked == 3 + assert result.attempted == 3 + runs.mark_backfill_finished.assert_called_once() + assert runs.mark_backfill_finished.call_args.kwargs["aborted_by_blocks"] is True + + +async def test_transport_failures_do_not_reset_genuine_block_streak() -> None: + """Сбой между блоками не должен обнулять счётчик отказов площадки. + + Иначе чередование «блок, таймаут, блок, таймаут…» держало бы прогон вечно + против площадки, которая нас уже не пускает. + """ + result, _ = await _run( + [_genuine_block(), _sidecar_500(), _genuine_block(), _sidecar_500(), _genuine_block()], + n=5, + max_consecutive_blocks=3, + ) + assert result.blocked == 3 + + +# ── сторож на молчаливый отказ ─────────────────────────────────────────────── + + +async def test_long_run_of_transport_failures_still_aborts() -> None: + """Если площадка отказывает молча, прогон обязан остановиться — просто позже. + + Без этого сторожа правка превратила бы хайртриггер в отсутствие тормоза. + """ + result, _ = await _run([_sidecar_500()] * 30, n=30, max_consecutive_soft_failures=10) + assert result.attempted == 10 + assert result.failed == 10 + + +async def test_soft_threshold_is_configurable() -> None: + """Порог читается из params — расписание должно уметь его двигать.""" + result, _ = await _run([_sidecar_500()] * 30, n=30, max_consecutive_soft_failures=4) + assert result.attempted == 4 + + +async def test_success_resets_the_soft_streak() -> None: + """Удачная карточка обнуляет серию — иначе редкие сбои копились бы за весь батч + и рвали прогон, в котором всё хорошо.""" + seq = ([_sidecar_500()] * 3 + [None]) * 3 + [None] * 6 + result, _ = await _run(seq, n=18, max_consecutive_soft_failures=4) + assert result.attempted == 18 + assert result.enriched == 9