fix(tradein/support): один повтор терял каждое одиннадцатое сообщение в поддержку #3309
3 changed files with 249 additions and 10 deletions
|
|
@ -94,11 +94,33 @@ _send_limiter = SlidingWindowLimiter(limit=_SEND_RATE_LIMIT, window_s=_SEND_RATE
|
|||
# #tgsupport-web review H1: интерактивный HTTP-запрос НЕ МОЖЕТ наследовать
|
||||
# воркерную политику ретраев `TelegramClient` (по умолчанию — до 5 попыток, на
|
||||
# 429 спит `retry_after` Telegram'а — для группы штатно 30-60с, на 5xx backoff до
|
||||
# 30с — легальный суммарный бюджет минуты). Узкий бюджет здесь: 1 повтор, короткий
|
||||
# timeout — интерактивный клиент должен получить ответ (даже если это ошибка)
|
||||
# за секунды, а не висеть до исчерпания воркерных ретраев.
|
||||
_INTERACTIVE_SEND_TIMEOUT_S = 10.0
|
||||
_INTERACTIVE_SEND_MAX_RETRIES = 1
|
||||
# 30с — легальный суммарный бюджет минуты). Узкий бюджет здесь: интерактивный
|
||||
# клиент должен получить ответ (даже если это ошибка) за секунды, а не висеть до
|
||||
# исчерпания воркерных ретраев.
|
||||
#
|
||||
# Числа подобраны по замеру прода 01.09.2026 (#tgsupport-retry), а не на глаз.
|
||||
# Что измерено на самом хосте, из контейнера бота:
|
||||
# - канал до api.telegram.org рвётся постоянно: 353 ConnectTimeout за сутки в
|
||||
# логе long-polling'а; доля отказов на попытку 15-38% всплесками (пять проб:
|
||||
# 3/8, 15/40, 5/20, 3/20, 1/25). Транспорт ни при чём — httpx и сырой сокет
|
||||
# отваливаются одинаково (25% против 35% в чередующемся замере);
|
||||
# - успешный запрос отвечает за 0.13с, максимум из 25 проб — 0.18с;
|
||||
# - неудачный НИКОГДА не отваливается быстро: все отказы упираются в таймаут
|
||||
# целиком (10.02с при timeout=10.0), быстрых — ноль;
|
||||
# - через `SCRAPER_PROXY_URL` не легчает, а хуже: 0 из 20. Прокси не решение.
|
||||
#
|
||||
# Отсюда три следствия. Таймаут 10с был чистой платой за неудачу (успех не занимает
|
||||
# и половины секунды) — снижен до 5с, это ~28-кратный запас к измеренному максимуму.
|
||||
# Одного повтора мало: при 30% отказов на попытку до пользователя доходило ~9%
|
||||
# отказов, то есть каждое одиннадцатое сообщение терялось с 502; три повтора уводят
|
||||
# это к ~0.8%. Экспоненциальная пауза 2→4→8с осмысленна против троттлинга, но здесь
|
||||
# отказ — неустановленное соединение, паузе нечего пережидать, поэтому потолок 1с:
|
||||
# он же не даёт `retry_after` из 429 (для группы штатные 30-60с) умножиться на число
|
||||
# попыток. Худший случай: 4 попытки × 5с + 3 паузы × 1с = 23с, и он требует четырёх
|
||||
# отказов подряд. Типичный случай не меняется — 0.13с.
|
||||
_INTERACTIVE_SEND_TIMEOUT_S = 5.0
|
||||
_INTERACTIVE_SEND_MAX_RETRIES = 3
|
||||
_INTERACTIVE_SEND_MAX_BACKOFF_S = 1.0
|
||||
|
||||
# #tgsupport-web review M5: без LIMIT каждое монтирование виджета на старом
|
||||
# треде отдавало бы ВЕСЬ лог переписки. См. `web_support_storage.list_messages`.
|
||||
|
|
@ -206,6 +228,7 @@ async def send_support_message(
|
|||
# review H1: узкий интерактивный бюджет — НЕ воркерные 5 ретраев/минуты.
|
||||
timeout=_INTERACTIVE_SEND_TIMEOUT_S,
|
||||
max_retries=_INTERACTIVE_SEND_MAX_RETRIES,
|
||||
max_backoff=_INTERACTIVE_SEND_MAX_BACKOFF_S,
|
||||
)
|
||||
except TelegramApiError:
|
||||
# НЕ логируем payload.text (переписка — ПДн) и НЕ логируем токен (его в
|
||||
|
|
@ -394,6 +417,7 @@ async def send_anon_support_message(
|
|||
message_thread_id=settings.telegram_support_topic_id or None,
|
||||
timeout=_INTERACTIVE_SEND_TIMEOUT_S,
|
||||
max_retries=_INTERACTIVE_SEND_MAX_RETRIES,
|
||||
max_backoff=_INTERACTIVE_SEND_MAX_BACKOFF_S,
|
||||
)
|
||||
except TelegramApiError:
|
||||
# Ни текст сообщения (ПДн), ни токен (bearer треда) в лог не попадают.
|
||||
|
|
|
|||
|
|
@ -105,10 +105,26 @@ class TelegramClient:
|
|||
*,
|
||||
timeout: float | None = None,
|
||||
max_retries: int = _DEFAULT_MAX_RETRIES,
|
||||
max_backoff: float | None = None,
|
||||
) -> Any:
|
||||
"""POST `method` с JSON-телом `payload`. Ретраит 429/5xx/network, иначе raise сразу."""
|
||||
"""POST `method` с JSON-телом `payload`. Ретраит 429/5xx/network, иначе raise сразу.
|
||||
|
||||
`max_backoff` (#tgsupport-retry) — потолок паузы МЕЖДУ попытками. По
|
||||
умолчанию `_MAX_BACKOFF_S` (30с) и полный `retry_after` из тела 429 — это
|
||||
воркерная политика, она НЕ меняется. Интерактивный вызывающий передаёт узкий
|
||||
потолок, потому что у него другой характер отказа: замер прода 01.09.2026 —
|
||||
успешный запрос к api.telegram.org отвечает за 0.13с (максимум из 25 проб —
|
||||
0.18с), а неудачный ВСЕГДА упирается в таймаут целиком (ConnectTimeout, ни
|
||||
одного быстрого отказа). Это не троттлинг, а неустановленное соединение:
|
||||
экспоненциальная пауза 2→4→8с не даёт удалённой стороне «остыть», она просто
|
||||
добавляет 14 секунд к ожиданию пользователя. Потолок применяется и к 429:
|
||||
иначе рост `max_retries` умножил бы Telegram-овский `retry_after` (для группы
|
||||
это штатные 30-60с) на число попыток и подвесил бы синхронный HTTP-запрос на
|
||||
минуты — ровно то, от чего предостерегает докстринг `send_message`.
|
||||
"""
|
||||
url = f"{self._base}/{method}"
|
||||
effective_timeout = timeout if timeout is not None else self._timeout
|
||||
backoff_cap = _MAX_BACKOFF_S if max_backoff is None else max_backoff
|
||||
attempt = 0
|
||||
|
||||
while True:
|
||||
|
|
@ -133,9 +149,9 @@ class TelegramClient:
|
|||
reason,
|
||||
)
|
||||
raise
|
||||
backoff = min(2.0**attempt, _MAX_BACKOFF_S)
|
||||
backoff = min(2.0**attempt, backoff_cap)
|
||||
logger.warning(
|
||||
"tg client: %s — network error (попытка %d/%d): %s — retry через %.0fs",
|
||||
"tg client: %s — network error (попытка %d/%d): %s — retry через %.1fs",
|
||||
method,
|
||||
attempt,
|
||||
max_retries,
|
||||
|
|
@ -147,6 +163,13 @@ class TelegramClient:
|
|||
|
||||
if response.status_code == 429:
|
||||
retry_after = _extract_retry_after(response)
|
||||
if max_backoff is not None:
|
||||
# Потолок на retry_after — ТОЛЬКО когда его попросили явно.
|
||||
# Воркеру Telegram-овские 30-60с надо уважать целиком, иначе
|
||||
# мы долбимся в 429 и заводим лимит жёстче; интерактивному
|
||||
# пути столько ждать нельзя ни при каких обстоятельствах —
|
||||
# за ним стоит открытый HTTP-запрос от браузера.
|
||||
retry_after = min(retry_after, max_backoff)
|
||||
if attempt > max_retries:
|
||||
error_code, description = _error_from_body(response)
|
||||
logger.error("tg client: %s — 429 после %d попыток, сдаёмся", method, attempt)
|
||||
|
|
@ -171,9 +194,9 @@ class TelegramClient:
|
|||
attempt,
|
||||
)
|
||||
raise TelegramApiError(method, error_code, description)
|
||||
backoff = min(2.0**attempt, _MAX_BACKOFF_S)
|
||||
backoff = min(2.0**attempt, backoff_cap)
|
||||
logger.warning(
|
||||
"tg client: %s — HTTP %d (попытка %d/%d) — retry через %.0fs",
|
||||
"tg client: %s — HTTP %d (попытка %d/%d) — retry через %.1fs",
|
||||
method,
|
||||
response.status_code,
|
||||
attempt,
|
||||
|
|
@ -251,6 +274,7 @@ class TelegramClient:
|
|||
reply_to_message_id: int | None = None,
|
||||
timeout: float | None = None,
|
||||
max_retries: int | None = None,
|
||||
max_backoff: float | None = None,
|
||||
) -> dict[str, Any]:
|
||||
"""sendMessage — текстовое сообщение (заголовки, приветствия, уведомления об ошибке).
|
||||
|
||||
|
|
@ -272,5 +296,7 @@ class TelegramClient:
|
|||
kwargs["timeout"] = timeout
|
||||
if max_retries is not None:
|
||||
kwargs["max_retries"] = max_retries
|
||||
if max_backoff is not None:
|
||||
kwargs["max_backoff"] = max_backoff
|
||||
result = await self._request("sendMessage", payload, **kwargs)
|
||||
return result if isinstance(result, dict) else {}
|
||||
|
|
|
|||
189
tradein-mvp/backend/tests/test_tgsupport_retry_budget.py
Normal file
189
tradein-mvp/backend/tests/test_tgsupport_retry_budget.py
Normal file
|
|
@ -0,0 +1,189 @@
|
|||
"""Бюджет ретраев интерактивной отправки в поддержку (#tgsupport-retry).
|
||||
|
||||
Замер прода 01.09.2026, из контейнера бота: канал до api.telegram.org рвётся
|
||||
всплесками (15-38% отказов на попытку, 353 ConnectTimeout за сутки в логе
|
||||
long-polling'а), успешный запрос отвечает за 0.13с, а неудачный ВСЕГДА упирается
|
||||
в таймаут целиком — быстрых отказов ноль. При одном повторе до пользователя
|
||||
доходило ~9% отказов; тесты ниже фиксируют новый бюджет и то, ЧТО ИМЕННО в нём
|
||||
нельзя сломать: воркерная политика ретраев остаётся прежней.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
from typing import Any
|
||||
|
||||
import httpx
|
||||
import pytest
|
||||
|
||||
from app.api.v1 import support as support_module
|
||||
from app.services.tgbot import client as client_module
|
||||
from app.services.tgbot.client import TelegramApiError, TelegramClient
|
||||
|
||||
|
||||
class _SleepSpy:
|
||||
"""Подменяет asyncio.sleep — паузы не ждём, а записываем."""
|
||||
|
||||
def __init__(self) -> None:
|
||||
self.slept: list[float] = []
|
||||
|
||||
async def __call__(self, seconds: float) -> None:
|
||||
self.slept.append(seconds)
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def sleep_spy(monkeypatch: pytest.MonkeyPatch) -> _SleepSpy:
|
||||
spy = _SleepSpy()
|
||||
monkeypatch.setattr(client_module.asyncio, "sleep", spy)
|
||||
return spy
|
||||
|
||||
|
||||
def _always_network_error(monkeypatch: pytest.MonkeyPatch) -> None:
|
||||
"""Каждая попытка — ConnectTimeout, ровно как на проде."""
|
||||
|
||||
class _Boom:
|
||||
async def __aenter__(self) -> Any:
|
||||
return self
|
||||
|
||||
async def __aexit__(self, *_: Any) -> None:
|
||||
return None
|
||||
|
||||
async def post(self, *_: Any, **__: Any) -> Any:
|
||||
raise httpx.ConnectTimeout("connect timeout")
|
||||
|
||||
monkeypatch.setattr(client_module.httpx, "AsyncClient", lambda **_: _Boom())
|
||||
|
||||
|
||||
def _always_429(monkeypatch: pytest.MonkeyPatch, retry_after: float) -> None:
|
||||
class _Throttled:
|
||||
async def __aenter__(self) -> Any:
|
||||
return self
|
||||
|
||||
async def __aexit__(self, *_: Any) -> None:
|
||||
return None
|
||||
|
||||
async def post(self, *_: Any, **__: Any) -> httpx.Response:
|
||||
return httpx.Response(
|
||||
429,
|
||||
json={
|
||||
"ok": False,
|
||||
"error_code": 429,
|
||||
"description": "Too Many Requests",
|
||||
"parameters": {"retry_after": retry_after},
|
||||
},
|
||||
)
|
||||
|
||||
monkeypatch.setattr(client_module.httpx, "AsyncClient", lambda **_: _Throttled())
|
||||
|
||||
|
||||
# --- потолок отката в клиенте -------------------------------------------------
|
||||
|
||||
|
||||
async def test_max_backoff_caps_network_retry_pauses(
|
||||
monkeypatch: pytest.MonkeyPatch, sleep_spy: _SleepSpy
|
||||
) -> None:
|
||||
"""С потолком 1с паузы между попытками не растут 2→4→8."""
|
||||
_always_network_error(monkeypatch)
|
||||
tg = TelegramClient("fake-token")
|
||||
|
||||
with pytest.raises(httpx.ConnectTimeout):
|
||||
await tg.send_message(chat_id=-1, text="x", max_retries=3, max_backoff=1.0)
|
||||
|
||||
# 3 повтора → 3 паузы, каждая не выше потолка.
|
||||
assert sleep_spy.slept == [1.0, 1.0, 1.0]
|
||||
|
||||
|
||||
async def test_without_max_backoff_worker_policy_is_unchanged(
|
||||
monkeypatch: pytest.MonkeyPatch, sleep_spy: _SleepSpy
|
||||
) -> None:
|
||||
"""Без явного потолка откат прежний экспоненциальный — воркеры не задеты."""
|
||||
_always_network_error(monkeypatch)
|
||||
tg = TelegramClient("fake-token")
|
||||
|
||||
with pytest.raises(httpx.ConnectTimeout):
|
||||
await tg.send_message(chat_id=-1, text="x", max_retries=3)
|
||||
|
||||
assert sleep_spy.slept == [2.0, 4.0, 8.0]
|
||||
|
||||
|
||||
async def test_max_backoff_caps_429_retry_after(
|
||||
monkeypatch: pytest.MonkeyPatch, sleep_spy: _SleepSpy
|
||||
) -> None:
|
||||
"""Главное, ради чего потолок нужен на 429: иначе рост max_retries умножил бы
|
||||
retry_after (для группы штатные 30-60с) на число попыток и подвесил бы
|
||||
синхронный HTTP-запрос на минуты."""
|
||||
_always_429(monkeypatch, retry_after=60.0)
|
||||
tg = TelegramClient("fake-token")
|
||||
|
||||
with pytest.raises(TelegramApiError):
|
||||
await tg.send_message(chat_id=-1, text="x", max_retries=3, max_backoff=1.0)
|
||||
|
||||
assert sleep_spy.slept == [1.0, 1.0, 1.0]
|
||||
assert sum(sleep_spy.slept) < 5.0
|
||||
|
||||
|
||||
async def test_without_max_backoff_429_still_honours_retry_after(
|
||||
monkeypatch: pytest.MonkeyPatch, sleep_spy: _SleepSpy
|
||||
) -> None:
|
||||
"""Воркерный путь по-прежнему уважает retry_after целиком — не злим Telegram."""
|
||||
_always_429(monkeypatch, retry_after=60.0)
|
||||
tg = TelegramClient("fake-token")
|
||||
|
||||
with pytest.raises(TelegramApiError):
|
||||
await tg.send_message(chat_id=-1, text="x", max_retries=1)
|
||||
|
||||
assert sleep_spy.slept == [60.0]
|
||||
|
||||
|
||||
async def test_retry_count_is_attempts_minus_one(monkeypatch: pytest.MonkeyPatch) -> None:
|
||||
"""max_retries=N даёт N+1 попыток — от этого считается худший случай ожидания."""
|
||||
attempts = 0
|
||||
|
||||
class _Counting:
|
||||
async def __aenter__(self) -> Any:
|
||||
return self
|
||||
|
||||
async def __aexit__(self, *_: Any) -> None:
|
||||
return None
|
||||
|
||||
async def post(self, *_: Any, **__: Any) -> Any:
|
||||
nonlocal attempts
|
||||
attempts += 1
|
||||
raise httpx.ConnectTimeout("connect timeout")
|
||||
|
||||
monkeypatch.setattr(client_module.httpx, "AsyncClient", lambda **_: _Counting())
|
||||
monkeypatch.setattr(client_module.asyncio, "sleep", _SleepSpy())
|
||||
|
||||
tg = TelegramClient("fake-token")
|
||||
with pytest.raises(httpx.ConnectTimeout):
|
||||
await tg.send_message(chat_id=-1, text="x", max_retries=3, max_backoff=0.0)
|
||||
|
||||
assert attempts == 4
|
||||
|
||||
|
||||
# --- бюджет ручки поддержки ---------------------------------------------------
|
||||
|
||||
|
||||
def test_interactive_budget_constants() -> None:
|
||||
"""Значения подобраны по замеру, а не на глаз — см. комментарий в support.py."""
|
||||
assert support_module._INTERACTIVE_SEND_MAX_RETRIES == 3
|
||||
assert support_module._INTERACTIVE_SEND_TIMEOUT_S == 5.0
|
||||
assert support_module._INTERACTIVE_SEND_MAX_BACKOFF_S == 1.0
|
||||
|
||||
|
||||
def test_interactive_worst_case_stays_within_http_patience() -> None:
|
||||
"""Худший случай — все попытки в таймаут — обязан остаться десятками секунд,
|
||||
а не минутами: это синхронный request/response, за ним ждёт браузер."""
|
||||
attempts = support_module._INTERACTIVE_SEND_MAX_RETRIES + 1
|
||||
pauses = support_module._INTERACTIVE_SEND_MAX_RETRIES
|
||||
worst = (
|
||||
attempts * support_module._INTERACTIVE_SEND_TIMEOUT_S
|
||||
+ pauses * support_module._INTERACTIVE_SEND_MAX_BACKOFF_S
|
||||
)
|
||||
assert worst <= 30.0, f"худший случай {worst}с — слишком долго для интерактивного пути"
|
||||
|
||||
|
||||
def test_interactive_budget_is_narrower_than_worker_default() -> None:
|
||||
"""Смысл узкого бюджета: он обязан оставаться строго уже воркерного."""
|
||||
assert support_module._INTERACTIVE_SEND_MAX_RETRIES < client_module._DEFAULT_MAX_RETRIES
|
||||
assert support_module._INTERACTIVE_SEND_TIMEOUT_S < client_module._DEFAULT_TIMEOUT_S
|
||||
assert support_module._INTERACTIVE_SEND_MAX_BACKOFF_S < client_module._MAX_BACKOFF_S
|
||||
Loading…
Add table
Reference in a new issue