From c01ec805df10d3cbd5e02751ee743479a5e0831a Mon Sep 17 00:00:00 2001 From: bot-backend Date: Thu, 27 Aug 2026 21:58:51 +0300 Subject: [PATCH] =?UTF-8?q?fix(tradein/tgbot):=20=D0=B2=20=D0=BB=D0=BE?= =?UTF-8?q?=D0=B3=D0=B5=20=D1=81=D0=B5=D1=82=D0=B5=D0=B2=D0=BE=D0=B3=D0=BE?= =?UTF-8?q?=20=D1=81=D0=B1=D0=BE=D1=8F=20=D0=BD=D0=B5=20=D0=B1=D1=8B=D0=BB?= =?UTF-8?q?=D0=BE=20=D0=BF=D1=80=D0=B8=D1=87=D0=B8=D0=BD=D1=8B=20=E2=80=94?= =?UTF-8?q?=20=D1=82=D0=BE=D0=BB=D1=8C=D0=BA=D0=BE=20=D0=BF=D1=83=D1=81?= =?UTF-8?q?=D1=82=D0=BE=D1=82=D0=B0=20=D0=BF=D0=BE=D1=81=D0=BB=D0=B5=20?= =?UTF-8?q?=D0=B4=D0=B2=D0=BE=D0=B5=D1=82=D0=BE=D1=87=D0=B8=D1=8F?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Замер на проде 27.08: `getUpdates` падает 23 раза в сутки, 14 из них за один час. Ретрай почти всегда чинит с первой попытки, поэтому сообщений не теряется — теряется возможность понять, что происходит: network error (попытка 1/3): — retry через 2s После двоеточия пусто. У httpx.ReadError и httpx.ConnectError `str(exc)` пуст, а тип исключения в строку не попадал. По такому логу не отличить таймаут от обрыва соединения от сброса TLS, то есть 23 события в сутки не дают ни одной зацепки. Сеть при этом цела: сырой TLS до Telegram проходит 6 из 6 попыток за ~0.16s. Тип добавляется к тексту, а не вместо него: на исключениях с внятным сообщением диагностика не должна стать беднее прежней. Оба конца закреплены тестами — с пустым текстом и с непустым. Closes #3156 --- .../backend/app/services/tgbot/client.py | 15 +++++- .../tests/services/tgbot/test_client.py | 54 +++++++++++++++++++ 2 files changed, 67 insertions(+), 2 deletions(-) diff --git a/tradein-mvp/backend/app/services/tgbot/client.py b/tradein-mvp/backend/app/services/tgbot/client.py index faeeee66..377522f7 100644 --- a/tradein-mvp/backend/app/services/tgbot/client.py +++ b/tradein-mvp/backend/app/services/tgbot/client.py @@ -117,9 +117,20 @@ class TelegramClient: async with httpx.AsyncClient(timeout=effective_timeout) as client: response = await client.post(url, json=payload) except (httpx.TimeoutException, httpx.NetworkError) as exc: + # Тип исключения обязан попасть в строку (#3156). У + # httpx.ReadError и httpx.ConnectError `str(exc)` пуст, и лог + # выглядел так: «network error (попытка 1/3): — retry через 2s» + # — после двоеточия пустота. По такой строке не отличить таймаут + # от обрыва соединения от сброса TLS, то есть диагностировать + # нечего. Замер на проде 27.08: 23 срабатывания за сутки, ни + # одной строки, по которой можно было бы что-то сказать. + reason = f"{type(exc).__name__}: {exc}" if str(exc) else type(exc).__name__ if attempt > max_retries: logger.error( - "tg client: %s — network error после %d попыток: %s", method, attempt, exc + "tg client: %s — network error после %d попыток: %s", + method, + attempt, + reason, ) raise backoff = min(2.0**attempt, _MAX_BACKOFF_S) @@ -128,7 +139,7 @@ class TelegramClient: method, attempt, max_retries, - exc, + reason, backoff, ) await asyncio.sleep(backoff) diff --git a/tradein-mvp/backend/tests/services/tgbot/test_client.py b/tradein-mvp/backend/tests/services/tgbot/test_client.py index cd547f7f..6a09e9ba 100644 --- a/tradein-mvp/backend/tests/services/tgbot/test_client.py +++ b/tradein-mvp/backend/tests/services/tgbot/test_client.py @@ -162,3 +162,57 @@ async def test_optional_thread_and_reply_params_omitted_when_falsy() -> None: await client.copy_message(chat_id=1, from_chat_id=2, message_id=3, message_thread_id=0) assert "message_thread_id" not in captured["body"] + + +async def test_network_error_log_names_the_exception_type(caplog) -> None: + """В логе сетевого сбоя обязан быть ТИП исключения, а не только текст (#3156). + + У `httpx.ReadError` и `httpx.ConnectError` текст обычно пуст, и строка + вырождалась в «network error (попытка 1/3): — retry через 2s»: после + двоеточия пустота. По ней невозможно отличить таймаут от обрыва соединения, + то есть 23 срабатывания в сутки на проде не давали ни одной зацепки. + + Проверяем именно пустой текст — на непустом дефект и не проявлялся. + """ + calls = {"n": 0} + + def handler(request: httpx.Request) -> httpx.Response: + calls["n"] += 1 + if calls["n"] == 1: + raise httpx.ReadError("") + return httpx.Response(200, json={"ok": True, "result": []}) + + _install_transport(handler) + with caplog.at_level("WARNING", logger="app.services.tgbot.client"): + await TelegramClient(token="t").get_updates(offset=0) + + warnings = [r.getMessage() for r in caplog.records if r.levelname == "WARNING"] + assert warnings, "не было предупреждения о сетевом сбое" + assert "ReadError" in warnings[0], ( + f"тип исключения не попал в лог, диагностировать нечем: {warnings[0]!r}" + ) + assert "network error (попытка 1/" in warnings[0], "формат строки изменился незаметно" + + +async def test_network_error_log_keeps_text_when_exception_has_one(caplog) -> None: + """Когда текст у исключения есть — он остаётся, а тип добавляется к нему. + + Обратный конец: правка не должна была ЗАМЕНИТЬ текст типом, иначе на + исключениях с внятным сообщением диагностика стала бы беднее прежней. + """ + calls = {"n": 0} + + def handler(request: httpx.Request) -> httpx.Response: + calls["n"] += 1 + if calls["n"] == 1: + raise httpx.ConnectTimeout("таймаут соединения") + return httpx.Response(200, json={"ok": True, "result": []}) + + _install_transport(handler) + with caplog.at_level("WARNING", logger="app.services.tgbot.client"): + await TelegramClient(token="t").get_updates(offset=0) + + warnings = [r.getMessage() for r in caplog.records if r.levelname == "WARNING"] + assert warnings, "не было предупреждения о сетевом сбое" + assert "ConnectTimeout" in warnings[0], f"нет типа: {warnings[0]!r}" + assert "таймаут соединения" in warnings[0], f"текст исключения потерян: {warnings[0]!r}"