Меньше шума: выключенные платежи не засоряют ленту ошибок, провал прокси-пробы пишется строкой вместо трейса #3483

Merged
lekss361 merged 1 commit from fix/3471-observability-noise into main 2026-09-12 11:18:35 +00:00
7 changed files with 239 additions and 30 deletions

View file

@ -19,6 +19,7 @@ from sentry_sdk.integrations.httpx import HttpxIntegration
from sentry_sdk.integrations.logging import LoggingIntegration
from sentry_sdk.integrations.sqlalchemy import SqlalchemyIntegration
from sentry_sdk.integrations.starlette import StarletteIntegration
from sentry_sdk.types import Event, Hint
from app.api.public import mera as public_mera
from app.api.v1 import (
@ -79,31 +80,43 @@ install_query_secret_filter()
# frontend), отдельного broker нет → мониторить нечего.
if settings.glitchtip_dsn:
from app.observability.sentry_scrub import (
drop_payments_disabled_event,
redact_telegram_bot_token,
scrub_payment_request_body,
scrub_public_address,
stabilize_retry_error_fingerprint,
)
def _before_send(event: dict[str, object], hint: dict[str, object]) -> dict[str, object] | None:
"""Композиция платёжный body-wipe + PII-scrub + Telegram bot-токен redaction +
RetryError fingerprint-стабилизация (#tgsupport-web, PR-D2, glitchtip-noise) —
см. app/tgbot_main.py._before_send (идентичная композиция без последнего шага,
тот бот geocoder не зовёт). Тот же риск: теперь этот процесс тоже держит
TelegramClient в стек-фреймах при ошибке sendMessage, а
def _before_send(event: Event, hint: Hint) -> Event | None:
"""Композиция payments-disabled drop + платёжный body-wipe + PII-scrub +
Telegram bot-токен redaction + RetryError fingerprint-стабилизация
(#tgsupport-web, PR-D2, glitchtip-noise, #3471) — см.
app/tgbot_main.py._before_send (идентичная композиция без последнего
шага, тот бот geocoder не зовёт). Тот же риск: теперь этот процесс тоже
держит TelegramClient в стек-фреймах при ошибке sendMessage, а
include_local_variables=False ниже первый рубеж защиты.
PR-D2: платёжный body-wipe идёт ПЕРВЫМ шагом, а не заменяет остальные
режет `request.data` целиком только для `/payments/*`, остальные пути
(extra/contexts/traceback) по-прежнему проходят ключ-based scrub и
token-redaction. Тот же обработчик передан ОБОИМ каналам ниже
(before_send и before_send_transaction) вчерашний баг в Птице закрыл
только error-канал, transaction-канал остался вообще без обработчика.
#3471: payments-disabled drop идёт ПЕРВЫМ шагом — это единственный
процесс из трёх entrypoint'ов, который реально держит ASGI-роут
`/api/v1/payments/*`, поэтому именно здесь события возникают; ранний
return None экономит остальную композицию на заведомо отбрасываемом
событии.
PR-D2: платёжный body-wipe идёт следующим шагом, а не заменяет
остальные режет `request.data` целиком только для `/payments/*`,
остальные пути (extra/contexts/traceback) по-прежнему проходят
ключ-based scrub и token-redaction. Тот же обработчик передан ОБОИМ
каналам ниже (before_send и before_send_transaction) вчерашний баг в
Птице закрыл только error-канал, transaction-канал остался вообще без
обработчика.
RetryError-стабилизация этот процесс обслуживает /api/v1/geocode/*
(suggest/lookup/reverse), которые ретраят Nominatim через tenacity; см.
sentry_scrub.stabilize_retry_error_fingerprint."""
scrubbed = scrub_payment_request_body(event, hint) # type: ignore[arg-type]
dropped = drop_payments_disabled_event(event, hint) # type: ignore[arg-type]
if dropped is None:
return None
scrubbed = scrub_payment_request_body(dropped, hint) # type: ignore[arg-type]
if scrubbed is None:
return None
# Публичный периметр МЕРЫ: тело запроса — это ровно введённый адрес, а

View file

@ -25,6 +25,7 @@ import re
from typing import Any
from sentry_sdk.types import Event
from starlette.exceptions import HTTPException as _StarletteHTTPException
from tenacity import RetryError
_REDACTED = "[REDACTED]"
@ -256,6 +257,41 @@ def scrub_payment_request_body(event: Event, _hint: dict[str, Any]) -> Event | N
return event
_PAYMENTS_DISABLED_DETAIL = "payments are disabled"
def drop_payments_disabled_event(event: Event, hint: dict[str, Any]) -> Event | None:
"""before_send-хук: роняет 503 "payments are disabled" из
`payments.py._require_enabled` (issue #3471, GlitchTip-группа TRADE-IN-3GG).
Источник внутренний IP смоук-проверки: кнопки оплаты во фронте нет,
клиентского трафика на эти пути нет вообще, а выключенный платёжный контур
(`settings.payments_enabled=False`) штатно отвечает 503 на каждый такой
запрос 167 событий за 29.08-12.09 размывали ленту, на этом фоне терялась
настоящая ошибка. Само поведение ручки НЕ меняется (503 остаётся)
фильтруется только репортинг в трекер: sentry_sdk `StarletteIntegration`
репортит любой `HTTPException` с кодом из `failed_request_status_codes`
(по умолчанию весь диапазон 5xx) как error-событие, даже когда исключение
штатно обработано FastAPI и превращено в корректный HTTP-ответ.
Матчим `isinstance` реального объекта исключения из `hint["exc_info"]` (тот
же контракт, что `stabilize_retry_error_fingerprint` ниже) + точный текст
`detail` НЕ код 503 сам по себе, чтобы не проглотить другие 503 (напр.
будущий maintenance-режим другого роутера).
"""
if not isinstance(event, dict):
return event
exc_info = hint.get("exc_info") if isinstance(hint, dict) else None
exc_value = exc_info[1] if exc_info and len(exc_info) > 1 else None
if (
isinstance(exc_value, _StarletteHTTPException)
and exc_value.status_code == 503
and exc_value.detail == _PAYMENTS_DISABLED_DETAIL
):
return None
return event
_PUBLIC_API_URL_SEGMENT = "/api/public/"
#: Хосты геокодеров: их URL несёт введённый адрес прямо в query.

View file

@ -43,14 +43,16 @@ if settings.glitchtip_dsn:
from sentry_sdk.integrations.httpx import HttpxIntegration
from sentry_sdk.integrations.logging import LoggingIntegration
from sentry_sdk.integrations.sqlalchemy import SqlalchemyIntegration
from sentry_sdk.types import Event, Hint
from app.observability.sentry_scrub import (
drop_payments_disabled_event,
scrub_payment_request_body,
scrub_pii_event,
stabilize_retry_error_fingerprint,
)
def _before_send(event: dict, hint: dict) -> dict | None: # type: ignore[type-arg]
def _before_send(event: Event, hint: Hint) -> Event | None:
"""PR-D2: этот процесс не держит ASGI-приложения (нет `request` в event
сегодня), но payments_confirm/payments_reconcile (PR-E, тот же
`tradein-scraper` контейнер) будут звать Т-Банк API отсюда belt-and-
@ -58,6 +60,13 @@ if settings.glitchtip_dsn:
`request`/`extra`. Тот же обработчик на оба канала ниже см.
app/main.py._before_send (идентичный мотив, не дублировать без причины).
#3471: payments-disabled drop — тот же belt-and-suspenders мотив, что и
payment body-wipe выше по докстрингу: этот процесс сегодня не отвечает
503 из `_require_enabled` (нет ASGI/роутов), реальный источник шума
`app/main.py`, но фильтр держим одинаковым во всех трёх entrypoint'ах,
чтобы поведение не разошлось, если payments-код когда-нибудь переедет
сюда же.
PII-scrub + RetryError fingerprint-стабилизация (glitchtip-noise) идут
следом за платёжным body-wipe: этот процесс гоняет
`geocode_missing_listings` (ночной batch, сотни адресов за прогон)
@ -66,13 +75,16 @@ if settings.glitchtip_dsn:
на КАЖДЫЙ адрес (RetryError.__str__() тащит нестабильный repr() Future).
См. sentry_scrub docstring.
"""
scrubbed = scrub_payment_request_body(event, hint) # type: ignore[arg-type]
dropped = drop_payments_disabled_event(event, hint) # type: ignore[arg-type]
if dropped is None:
return None
scrubbed = scrub_payment_request_body(dropped, hint) # type: ignore[arg-type]
if scrubbed is None:
return None
scrubbed = scrub_pii_event(scrubbed, hint)
scrubbed = scrub_pii_event(scrubbed, hint) # type: ignore[arg-type]
if scrubbed is None:
return None
return stabilize_retry_error_fingerprint(scrubbed, hint)
return stabilize_retry_error_fingerprint(scrubbed, hint) # type: ignore[arg-type,return-value]
sentry_sdk.init(
dsn=settings.glitchtip_dsn,

View file

@ -1309,6 +1309,8 @@ async def _probe_proxy(url: str) -> tuple[bool, str | None, int | None, str | No
транзиентный сбой узла перманентный бан, используется пока только для логов):
- "timeout" сеть недоступна/медленная (httpx.TimeoutException)
- "connect_error" прокси не поднят/не слушает/DNS (httpx.ConnectError)
- "proxy_error" сам прокси отверг соединение (httpx.ProxyError, напр. 407 от
провайдера это состояние пула, а не инцидент; #3471)
- "http_error" ipify ответил ошибкой через прокси (auth/upstream)
- "other" прочее
@ -1328,6 +1330,14 @@ async def _probe_proxy(url: str) -> tuple[bool, str | None, int | None, str | No
except httpx.ConnectError:
logger.warning("proxy_pool: health probe connect_error proxy=%s", _mask(url))
return False, None, None, "connect_error"
except httpx.ProxyError as exc:
# #3471: сам прокси-провайдер отверг соединение (чаще всего 407 —
# исчерпан лимит/просрочен пакет) — штатный исход health-пробы, не
# инцидент приложения. Одна строка без трейса: узел + причина текстом
# исключения, полный traceback здесь не несёт новой информации и только
# засорял логи (184 строки/сутки, #3471).
logger.warning("proxy_pool: health probe proxy_error proxy=%s reason=%s", _mask(url), exc)
return False, None, None, "proxy_error"
except httpx.HTTPStatusError as exc:
logger.warning(
"proxy_pool: health probe http_error proxy=%s status=%s",

View file

@ -26,7 +26,6 @@ import logging
import os
import signal
from contextlib import suppress
from typing import Any
from app.core.config import settings
from app.core.db import SessionLocal
@ -57,18 +56,20 @@ if settings.glitchtip_dsn:
import sentry_sdk
from sentry_sdk.integrations.httpx import HttpxIntegration
from sentry_sdk.integrations.logging import LoggingIntegration
from sentry_sdk.types import Event, Hint
from app.observability.sentry_scrub import (
drop_payments_disabled_event,
redact_telegram_bot_token,
scrub_payment_request_body,
scrub_pii_event,
)
def _before_send(event: Any, hint: dict[str, Any]) -> Any:
"""Композиция платёжный body-wipe (PR-D2) + PII-scrub (form-данные) +
Telegram bot-токен redaction (#tgsupport review). Токен утекает ДВУМЯ
независимыми векторами, которые `include_local_variables=False` ниже и
этот хук закрывают вместе:
def _before_send(event: Event, hint: Hint) -> Event | None:
"""Композиция payments-disabled drop (#3471) + платёжный body-wipe (PR-D2) +
PII-scrub (form-данные) + Telegram bot-токен redaction (#tgsupport review).
Токен утекает ДВУМЯ независимыми векторами, которые
`include_local_variables=False` ниже и этот хук закрывают вместе:
1. `include_local_variables=True` (sentry_sdk default) кладёт stack-frame
locals (`self._base`/`url` в `TelegramClient._request`) в traceback
закрыто через `include_local_variables=False` в `sentry_sdk.init`.
@ -78,18 +79,22 @@ if settings.glitchtip_dsn:
belt-and-suspenders на случай #1 (если include_local_variables
случайно вернут) И на span data.
Платёжный body-wipe belt-and-suspenders: этот процесс не держит ASGI-
приложения (нет `request` в event сегодня), но тот же обработчик передан
ОБОИМ каналам ниже (before_send/before_send_transaction) ради единообразия
со всеми точками инициализации sentry_sdk в проекте (см. app/main.py).
Payments-disabled drop и платёжный body-wipe belt-and-suspenders: этот
процесс не держит ASGI-приложения (нет `request`/HTTPException в event
сегодня, реальный источник 503 app/main.py), но тот же обработчик
передан ОБОИМ каналам ниже (before_send/before_send_transaction) ради
единообразия со всеми точками инициализации sentry_sdk в проекте.
"""
scrubbed = scrub_payment_request_body(event, hint)
dropped = drop_payments_disabled_event(event, hint) # type: ignore[arg-type]
if dropped is None:
return None
scrubbed = scrub_payment_request_body(dropped, hint) # type: ignore[arg-type]
if scrubbed is None:
return None
scrubbed = scrub_pii_event(scrubbed, hint)
scrubbed = scrub_pii_event(scrubbed, hint) # type: ignore[arg-type]
if scrubbed is None:
return None
return redact_telegram_bot_token(scrubbed, hint)
return redact_telegram_bot_token(scrubbed, hint) # type: ignore[arg-type,return-value]
sentry_sdk.init(
dsn=settings.glitchtip_dsn,

View file

@ -50,6 +50,7 @@ os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:
from datetime import UTC, datetime, timedelta
from typing import Any
import httpx
import pytest
from app.services import proxy_pool
@ -1527,3 +1528,74 @@ def test_clear_source_bans_resets_escalation() -> None:
assert ban["ban_count"] == 1
expected = datetime.now(UTC) + timedelta(hours=SOURCE_BAN_BASE_HOURS)
assert abs((ban["banned_until"] - expected).total_seconds()) < 60
# ── health-probe failure logging (#3471 — GlitchTip/log noise) ──────────────
# httpx.ProxyError (типично 407 от провайдера) раньше падал в generic
# `except Exception: ... exc_info=True` внутри `_probe_proxy` — полный traceback
# на КАЖДЫЙ провал, хотя это штатное состояние пула (184 строки/сутки на
# проде), а не инцидент приложения. Тесты ниже бьют по РЕАЛЬНОМУ `_probe_proxy`
# (не монки-заглушке, как в тестах `run_proxy_healthcheck` выше) — только так
# видно, что осталось от логирования при живом httpx-исключении.
async def test_probe_proxy_proxy_error_logs_single_line_without_traceback(
monkeypatch: pytest.MonkeyPatch,
caplog: pytest.LogCaptureFixture,
) -> None:
async def _broken_get(self: httpx.AsyncClient, *args: Any, **kwargs: Any) -> httpx.Response:
raise httpx.ProxyError("407 Proxy Authentication Required")
monkeypatch.setattr(httpx.AsyncClient, "get", _broken_get)
with caplog.at_level("WARNING", logger="app.services.proxy_pool"):
ok, exit_ip, latency_ms, fail_kind = await proxy_pool._probe_proxy(
"http://u:p@h1:8080"
)
assert ok is False
assert exit_ip is None
assert latency_ms is None
assert fail_kind == "proxy_error"
records = [r for r in caplog.records if r.name == "app.services.proxy_pool"]
assert len(records) == 1, "провал ipify-пробы обязан лечь ОДНОЙ строкой, не пачкой"
record = records[0]
assert record.exc_info is None, "проба — штатная операция, полный traceback не нужен"
assert "proxy_error" in record.message
assert "407" in record.message # причина (текст исключения) видна без трейса
async def test_healthcheck_counts_proxy_error_as_failed_without_traceback(
monkeypatch: pytest.MonkeyPatch,
caplog: pytest.LogCaptureFixture,
) -> None:
"""Итоговая строка `checked=.../ok=.../failed=...` не ломается провалом
вида ProxyError, а сам провал не тащит traceback в лог прогона."""
db = FakeSession([_proxy(1, fails=0)])
async def _broken_get(self: httpx.AsyncClient, *args: Any, **kwargs: Any) -> httpx.Response:
raise httpx.ProxyError("407 Proxy Authentication Required")
monkeypatch.setattr(httpx.AsyncClient, "get", _broken_get)
# INFO (не WARNING): итоговая сводка `healthcheck done` логируется на INFO —
# порог ниже WARNING нужен, чтобы её тоже поймать в этом же прогоне.
with caplog.at_level("INFO", logger="app.services.proxy_pool"):
counters = await proxy_pool.run_proxy_healthcheck(db) # type: ignore[arg-type]
assert counters["checked"] == 1
assert counters["ok"] == 0
assert counters["failed"] == 1
assert db._by_id(1)["consecutive_fails"] == 1
summary = [
r
for r in caplog.records
if r.name == "app.services.proxy_pool" and "healthcheck done" in r.message
]
assert len(summary) == 1
assert "checked=1" in summary[0].message
assert "ok=0" in summary[0].message
assert "failed=1" in summary[0].message
assert not any(r.exc_info for r in caplog.records if r.name == "app.services.proxy_pool")

View file

@ -13,6 +13,7 @@ import pytest
os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:5432/test")
from app.observability.sentry_scrub import (
drop_payments_disabled_event,
redact_telegram_bot_token,
scrub_payment_request_body,
scrub_pii_event,
@ -627,3 +628,63 @@ def test_scrub_pii_event_httpx_url_query_stabilization_leaves_unrelated_text_unt
out = scrub_pii_event(event, {})
assert out is not None
assert out["extra"]["note"] == benign
# ── payments-disabled drop (issue #3471, GlitchTip-группа TRADE-IN-3GG) ─────
# 503 из `payments.py._require_enabled` — штатный ответ выключенного
# kill-switch'а, а не инцидент: sentry_sdk `StarletteIntegration` репортит его
# как error-событие только потому, что 503 попадает в дефолтный диапазон
# `failed_request_status_codes` (5xx), хотя FastAPI обработал исключение
# штатно. 167 событий/2 недели от внутреннего IP смоук-проверки (кнопки оплаты
# во фронте нет) размывали ленту. Фильтр не должен трогать поведение самой
# ручки (503 остаётся) и не должен глотать другие ошибки — включая другие 503.
from fastapi import HTTPException # noqa: E402
def _exc_info_hint(exc: BaseException) -> dict:
"""Та же форма hint, что sentry_sdk реально передаёт в before_send —
`exc_info = (type, value, traceback)` (см. `_hint_for` выше по файлу)."""
return {"exc_info": (type(exc), exc, exc.__traceback__)}
def test_drop_payments_disabled_event_drops_the_503() -> None:
exc = HTTPException(status_code=503, detail="payments are disabled")
event = {"level": "error", "exception": {"values": [{"type": "HTTPException"}]}}
assert drop_payments_disabled_event(event, _exc_info_hint(exc)) is None
def test_drop_payments_disabled_event_leaves_other_errors_untouched() -> None:
"""Обычная ошибка (не платёжный kill-switch) должна долетать до GlitchTip
без изменений фильтр специфичен по (status_code, detail), а не по 5xx."""
exc = ValueError("boom")
event = {"level": "error"}
out = drop_payments_disabled_event(event, _exc_info_hint(exc))
assert out is event
def test_drop_payments_disabled_event_leaves_other_503s_untouched() -> None:
"""Другой 503 с другим текстом (напр. будущий maintenance-режим другого
роутера) не должен ложно схлопнуться с платёжным kill-switch'ем."""
exc = HTTPException(status_code=503, detail="service temporarily unavailable")
event = {"level": "error"}
out = drop_payments_disabled_event(event, _exc_info_hint(exc))
assert out is event
def test_drop_payments_disabled_event_leaves_matching_detail_wrong_status_untouched() -> None:
"""Тот же текст detail, но другой status_code — не платёжный kill-switch."""
exc = HTTPException(status_code=500, detail="payments are disabled")
event = {"level": "error"}
out = drop_payments_disabled_event(event, _exc_info_hint(exc))
assert out is event
def test_drop_payments_disabled_event_no_exc_info_untouched() -> None:
event = {"level": "error"}
out = drop_payments_disabled_event(event, {})
assert out is event
def test_drop_payments_disabled_event_handles_non_dict_event() -> None:
assert drop_payments_disabled_event(None, {}) is None # type: ignore[arg-type]