All checks were successful
CI / changes (pull_request) Successful in 10s
CI Trade-In / changes (pull_request) Successful in 8s
CI Trade-In / backend-tests (pull_request) Has been skipped
CI Trade-In / browser-tests (pull_request) Has been skipped
CI Trade-In / frontend-checks (pull_request) Has been skipped
CI / frontend-tests (pull_request) Has been skipped
CI / openapi-codegen-check (pull_request) Successful in 1m48s
CI / backend-tests (pull_request) Successful in 22m26s
Путь Selectel-Telegram теряет соединения. Замер 26.08 с Poincare, 40 подключений к закреплённому (#3093) 149.154.167.220: успешно 37 из 40, отказов 3 (7.5%) - все TimeoutError время успешных: min 0.14s, медиана 0.15s, max 0.17s Отказы происходят на стадии ПОДКЛЮЧЕНИЯ - быстрые стабильные успехи на фоне редких таймаутов. Три остальных дата-центра Telegram с Selectel недостижимы вовсе, так что закрепление адреса потери убрать не может: запасного адреса нет. Бот это переживает своими ретраями (106 таймаутов за сутки, 97 лечатся первой же повторной попыткой), а вот алерты - нет. uptime-healthcheck.sh: был один curl и `|| log WARN` - каждый отказ терял уведомление целиком. Сторож, который не может дозваться, - худший вид самоскрывающейся поломки: чем хуже дела на проде, тем выше шанс, что о них не сообщат. Ирония в том, что ниже в этом же файле HTTP-проверки уже повторяются циклом: ретраили то, что измеряют, но не то, чем докладывают. lib-backup.sh: тоже один curl, но с падением в почту (#3070). Алерт не терялся, зато каждый транзиентный таймаут впустую сжигал последнее средство вместо простого переподключения. Стало: цикл из трёх попыток в обеих notify(). Не `curl --retry` - семантика --max-time при ретраях зависит от версии curl, а цикл даёт таймаут на КАЖДУЮ попытку и повторяет идиому, уже принятую в uptime-healthcheck.sh. Дубль вместо потери - осознанный размен: sendMessage не идемпотентен, но отказ случается ДО отправки запроса, так что повтор почти никогда не продублирует доставленное. Лишний алерт безвреден, пропущенный - нет. Тесты (backend/tests/ops/test_3059_alert_retry.py, 7 шт) исполняют РЕАЛЬНЫЕ notify(), извлечённые из обоих скриптов, с подставным curl, отказывающим заданное число раз, и считают фактическое число попыток. Фальсификация: на исходных скриптах краснеют 6 из 7. Проходит только test_backup_falls_back_to_mail_when_telegram_is_really_down - он фиксирует сохранённое поведение, а не регресс. Проверено: `bash -n` обоих скриптов (та же проверка, что в CI - shellcheck там нет); конструкция `[[ ]] && cmd` в конце тела цикла безопасна под `set -euo pipefail`, который стоит в uptime-healthcheck.sh:25 (проверено исполнением, не рассуждением); tests/ops целиком - 22 passed.
188 lines
10 KiB
Python
188 lines
10 KiB
Python
"""Regression: алерт больше не теряется от одного сетевого отказа (#3059).
|
||
|
||
Что происходит. Путь Selectel→Telegram теряет соединения. Замер 26.08.2026 с
|
||
Poincare, 40 подключений к ЗАКРЕПЛЁННОМУ (#3093) 149.154.167.220:
|
||
|
||
успешно 37 из 40, отказов 3 (7.5%) — все TimeoutError
|
||
время успешных: min 0.14s, медиана 0.15s, max 0.17s
|
||
|
||
Отказы происходят на СТАДИИ ПОДКЛЮЧЕНИЯ (быстрые и стабильные успешные
|
||
попытки на фоне редких таймаутов), а не от перегрузки Telegram. Три остальных
|
||
дата-центра с Selectel недостижимы вовсе, поэтому запасного адреса нет и
|
||
закрепление (#3093) потери убрать не может — оно лишь выбирает единственный
|
||
работающий адрес.
|
||
|
||
Как это ломало алерты:
|
||
|
||
* `ops/uptime-healthcheck.sh` — ОДИН `curl`, дальше `|| log WARN`. Каждый
|
||
отказ терял уведомление целиком. Watchdog, который не может дозваться, —
|
||
худший вид самоскрывающейся поломки: чем хуже дела на проде, тем выше шанс,
|
||
что о них не сообщат. При этом сам файл ниже повторяет свои HTTP-ПРОВЕРКИ
|
||
циклом `for attempt in $(seq 1 ...)` — то есть ретраил то, что измеряет, но
|
||
не то, чем докладывает.
|
||
* `ops/lib-backup.sh` — тоже один `curl`, но с падением в запасной канал
|
||
(почта, #3070). Формально алерт не терялся, фактически КАЖДЫЙ транзиентный
|
||
таймаут впустую сжигал последнее средство вместо простого переподключения.
|
||
|
||
Фикс — цикл из трёх попыток в обеих `notify()`. Не `curl --retry`: семантика
|
||
`--max-time` при ретраях зависит от версии curl, а цикл гарантирует таймаут
|
||
на КАЖДУЮ попытку и повторяет идиому, уже принятую в uptime-healthcheck.sh.
|
||
|
||
Дубль вместо потери — осознанный размен: `sendMessage` не идемпотентен, но
|
||
отказ случается ДО отправки запроса, так что повтор почти никогда не
|
||
продублирует доставленное. Лишний алерт безвреден, пропущенный — нет.
|
||
|
||
ПОЧЕМУ ЭТОТ КЛАСС БАГОВ НЕ ЛОВИЛСЯ: одиночный `curl ... || log WARN` выглядит
|
||
безобидно при чтении — «ошибку же логируем». Виден он только замером частоты
|
||
отказов канала. Тесты ниже исполняют РЕАЛЬНЫЕ `notify()`, извлечённые из обоих
|
||
скриптов, с подставным `curl`, который отказывает заданное число раз, и
|
||
считают ФАКТИЧЕСКОЕ число попыток. Возврат к одиночному вызову уронит их
|
||
немедленно.
|
||
"""
|
||
|
||
from __future__ import annotations
|
||
|
||
import shutil
|
||
import subprocess
|
||
from pathlib import Path
|
||
|
||
import pytest
|
||
|
||
# backend/tests/ops/<этот файл> → корень репозитория
|
||
REPO_ROOT = Path(__file__).resolve().parents[3]
|
||
|
||
UPTIME = "ops/uptime-healthcheck.sh"
|
||
LIB_BACKUP = "ops/lib-backup.sh"
|
||
|
||
# См. подробное обоснование shutil.which в
|
||
# backend/tests/ops/test_2203_backup_trailer_grep_dashdash.py: голое "bash" на
|
||
# Windows с WSL резолвится в System32\bash.exe и ломает многокомандный `-c`.
|
||
BASH = shutil.which("bash")
|
||
if BASH is None: # pragma: no cover - окружение без bash не запустит эти тесты
|
||
pytest.skip("bash не найден в PATH — тест требует shell-исполнения", allow_module_level=True)
|
||
|
||
|
||
def _extract_function(script_rel: str, name: str = "notify") -> str:
|
||
"""Достаёт тело одной функции из скрипта — не весь файл.
|
||
|
||
Весь скрипт source'ить нельзя: uptime-healthcheck.sh ниже функций реально
|
||
ходит по прод-URL, а lib-backup.sh рассчитан на вызов из backup.sh.
|
||
|
||
Сопоставление точное (`name() {`), иначе `notify` поймал бы
|
||
`notify_fallback_mail` — соседнюю функцию в том же файле.
|
||
"""
|
||
path = REPO_ROOT / script_rel
|
||
assert path.is_file(), f"нет {path} — скрипт переехал, гейт ослеп"
|
||
lines = path.read_text(encoding="utf-8").splitlines()
|
||
head = f"{name}() {{"
|
||
start = next((i for i, line in enumerate(lines) if line.startswith(head)), None)
|
||
assert start is not None, f"{script_rel}: не нашёл функцию {name}()"
|
||
end = next((i for i in range(start + 1, len(lines)) if lines[i] == "}"), None)
|
||
assert end is not None, f"{script_rel}: не нашёл конец функции {name}()"
|
||
body = "\n".join(lines[start : end + 1])
|
||
assert "curl" in body, f"{script_rel}: извлечённое тело {name}() не содержит curl"
|
||
return body
|
||
|
||
|
||
# Заглушка curl: считает вызовы и отказывает первые $FAIL_TIMES раз.
|
||
# Код 28 — curl'овский "operation timeout", ровно то, что наблюдалось в замере.
|
||
_HARNESS = r"""
|
||
set -u
|
||
stubdir=$(mktemp -d)
|
||
trap 'rm -rf "$stubdir"' EXIT
|
||
export COUNTER="$stubdir/calls"
|
||
echo 0 > "$COUNTER"
|
||
export FAIL_TIMES=@@FAIL_TIMES@@
|
||
|
||
cat > "$stubdir/curl" <<'STUB'
|
||
#!/usr/bin/env bash
|
||
n=$(cat "$COUNTER")
|
||
n=$((n + 1))
|
||
echo "$n" > "$COUNTER"
|
||
if [ "$n" -le "$FAIL_TIMES" ]; then exit 28; fi
|
||
exit 0
|
||
STUB
|
||
chmod +x "$stubdir/curl"
|
||
export PATH="$stubdir:$PATH"
|
||
|
||
log() { echo "LOG: $*" >&2; }
|
||
notify_fallback_mail() { echo "FALLBACK_MAIL_CALLED" >&2; }
|
||
|
||
TELEGRAM_BOT_TOKEN=stub-token
|
||
TELEGRAM_CHAT_ID=stub-chat
|
||
CURL_TIMEOUT=1
|
||
NOTIFY_RETRY_DELAY=0
|
||
|
||
@@FUNC@@
|
||
|
||
notify "тестовый алерт"
|
||
echo "RC=$?"
|
||
echo "CURL_CALLS=$(cat "$COUNTER")"
|
||
"""
|
||
|
||
|
||
def _run_notify(script_rel: str, fail_times: int) -> tuple[int, str, str]:
|
||
"""Гоняет РЕАЛЬНУЮ notify() из скрипта с curl, падающим fail_times раз.
|
||
|
||
Возвращает (сколько раз позван curl, stdout, stderr).
|
||
"""
|
||
harness = _HARNESS.replace("@@FUNC@@", _extract_function(script_rel)).replace(
|
||
"@@FAIL_TIMES@@", str(fail_times)
|
||
)
|
||
proc = subprocess.run([BASH, "-c", harness], capture_output=True, timeout=30)
|
||
out = proc.stdout.decode("utf-8", errors="replace")
|
||
err = proc.stderr.decode("utf-8", errors="replace")
|
||
calls = next(
|
||
(int(line.split("=", 1)[1]) for line in out.splitlines() if line.startswith("CURL_CALLS=")),
|
||
-1,
|
||
)
|
||
assert calls >= 0, f"харнесс не отработал.\nstdout:\n{out}\nstderr:\n{err}"
|
||
return calls, out, err
|
||
|
||
|
||
@pytest.mark.parametrize("script_rel", [UPTIME, LIB_BACKUP])
|
||
def test_transient_failure_is_retried_not_lost(script_rel: str) -> None:
|
||
"""Один отказ — алерт всё равно доставляется со второй попытки.
|
||
|
||
Это ядро регресса: до фикса curl звался РОВНО ОДИН раз и первый же
|
||
таймаут (7.5% по замеру) означал потерю уведомления.
|
||
"""
|
||
calls, out, err = _run_notify(script_rel, fail_times=1)
|
||
assert calls == 2, f"{script_rel}: ожидалась повторная попытка, а curl позван {calls} раз"
|
||
assert "RC=0" in out, f"{script_rel}: notify() должна вернуть успех.\nstderr:\n{err}"
|
||
assert "НЕ ДОСТАВЛЕН" not in err, f"{script_rel}: доставленный алерт помечен потерянным"
|
||
|
||
|
||
@pytest.mark.parametrize("script_rel", [UPTIME, LIB_BACKUP])
|
||
def test_gives_up_after_three_attempts(script_rel: str) -> None:
|
||
"""Повторы ограничены: три попытки, а не бесконечный цикл.
|
||
|
||
Верхняя граница важна не меньше нижней — hourly-крон не должен зависать
|
||
на недоступном Telegram.
|
||
"""
|
||
calls, _out, _err = _run_notify(script_rel, fail_times=99)
|
||
assert calls == 3, f"{script_rel}: ожидалось ровно 3 попытки, а curl позван {calls} раз"
|
||
|
||
|
||
def test_uptime_reports_undelivered_alert_loudly() -> None:
|
||
"""Когда все три попытки провалились — это видно в логе, а не молча."""
|
||
_calls, _out, err = _run_notify(UPTIME, fail_times=99)
|
||
assert "НЕ ДОСТАВЛЕН" in err, f"недоставленный алерт должен логироваться громко.\n{err}"
|
||
|
||
|
||
def test_backup_does_not_burn_fallback_on_a_single_timeout() -> None:
|
||
"""Транзиентный таймаут не должен трогать запасной канал.
|
||
|
||
Почта (#3070) — последнее средство на случай, когда Telegram недоступен
|
||
ПО-НАСТОЯЩЕМУ. До фикса её дёргал каждый пропущенный SYN.
|
||
"""
|
||
_calls, _out, err = _run_notify(LIB_BACKUP, fail_times=1)
|
||
assert "FALLBACK_MAIL_CALLED" not in err, "запасной канал сожжён на одном транзиентном отказе"
|
||
|
||
|
||
def test_backup_falls_back_to_mail_when_telegram_is_really_down() -> None:
|
||
"""А когда Telegram действительно недоступен — почта всё-таки уходит."""
|
||
_calls, _out, err = _run_notify(LIB_BACKUP, fail_times=99)
|
||
assert err.count("FALLBACK_MAIL_CALLED") == 1, (
|
||
f"после трёх отказов ожидался ровно один вызов запасного канала.\n{err}"
|
||
)
|