fix(tradein/tgbot): в логе сетевого сбоя не было причины — только пустота после двоеточия
All checks were successful
CI / changes (pull_request) Successful in 10s
CI Trade-In / changes (pull_request) Successful in 8s
CI Trade-In / browser-tests (pull_request) Has been skipped
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 4m51s
All checks were successful
CI / changes (pull_request) Successful in 10s
CI Trade-In / changes (pull_request) Successful in 8s
CI Trade-In / browser-tests (pull_request) Has been skipped
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 4m51s
Замер на проде 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
This commit is contained in:
parent
084c3a2470
commit
c01ec805df
2 changed files with 67 additions and 2 deletions
|
|
@ -117,9 +117,20 @@ class TelegramClient:
|
||||||
async with httpx.AsyncClient(timeout=effective_timeout) as client:
|
async with httpx.AsyncClient(timeout=effective_timeout) as client:
|
||||||
response = await client.post(url, json=payload)
|
response = await client.post(url, json=payload)
|
||||||
except (httpx.TimeoutException, httpx.NetworkError) as exc:
|
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:
|
if attempt > max_retries:
|
||||||
logger.error(
|
logger.error(
|
||||||
"tg client: %s — network error после %d попыток: %s", method, attempt, exc
|
"tg client: %s — network error после %d попыток: %s",
|
||||||
|
method,
|
||||||
|
attempt,
|
||||||
|
reason,
|
||||||
)
|
)
|
||||||
raise
|
raise
|
||||||
backoff = min(2.0**attempt, _MAX_BACKOFF_S)
|
backoff = min(2.0**attempt, _MAX_BACKOFF_S)
|
||||||
|
|
@ -128,7 +139,7 @@ class TelegramClient:
|
||||||
method,
|
method,
|
||||||
attempt,
|
attempt,
|
||||||
max_retries,
|
max_retries,
|
||||||
exc,
|
reason,
|
||||||
backoff,
|
backoff,
|
||||||
)
|
)
|
||||||
await asyncio.sleep(backoff)
|
await asyncio.sleep(backoff)
|
||||||
|
|
|
||||||
|
|
@ -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)
|
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"]
|
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}"
|
||||||
|
|
|
||||||
Loading…
Add table
Reference in a new issue