Merge pull request 'fix(ops): алерт не теряется от одного сетевого отказа — ретрай в обеих notify() (#3059)' (#3095) from fix/3059-alert-retry into main

backend/tests/ops/test_3059_alert_retry.py

@@ -0,0 +1,188 @@
+"""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}"
+    )

ops/lib-backup.sh

@@ -45,13 +45,31 @@ notify() {
         return 0
     fi
 
-    curl -fsS --max-time 15 \
-        -X POST "https://api.telegram.org/bot${TELEGRAM_BOT_TOKEN}/sendMessage" \
-        -d "chat_id=${TELEGRAM_CHAT_ID}" \
-        -d "disable_web_page_preview=true" \
-        --data-urlencode "text=${text}" \
-        >/dev/null 2>&1 \
-        || { log "WARN: telegram sendMessage failed — пробую запасной канал"; notify_fallback_mail "$text"; }
+    # #3059: одиночный curl отправлял алерт «на удачу». Замер 26.08 с Poincare —
+    # 3 отказа на 40 подключений (7.5%) к закреплённому (#3093) 149.154.167.220,
+    # все таймаутом на СТАДИИ ПОДКЛЮЧЕНИЯ. То есть каждый двадцатый-тридцатый
+    # алерт впустую сжигал запасной канал (почту) вместо того, чтобы просто
+    # переподключиться: почта — последнее средство на случай, когда Telegram
+    # недоступен ПО-НАСТОЯЩЕМУ, а не пропустил один SYN.
+    #
+    # Повтор безопасен: отказ происходит до отправки запроса, поэтому дубль
+    # сообщения практически исключён, а пропущенный алерт о неудавшемся бэкапе
+    # — именно то, ради предотвращения чего этот файл и существует.
+    local attempt
+    for attempt in 1 2 3; do
+        if curl -fsS --max-time 15 \
+            -X POST "https://api.telegram.org/bot${TELEGRAM_BOT_TOKEN}/sendMessage" \
+            -d "chat_id=${TELEGRAM_CHAT_ID}" \
+            -d "disable_web_page_preview=true" \
+            --data-urlencode "text=${text}" \
+            >/dev/null 2>&1; then
+            [[ "$attempt" -gt 1 ]] && log "telegram sendMessage: доставлено с попытки ${attempt}"
+            return 0
+        fi
+        [[ "$attempt" -lt 3 ]] && sleep "${NOTIFY_RETRY_DELAY:-2}"
+    done
+    log "WARN: telegram sendMessage failed — 3 попытки подряд, пробую запасной канал"
+    notify_fallback_mail "$text"
 }
 
 # --- запасной канал оповещения (#3059) ----------------------------------

ops/uptime-healthcheck.sh

@@ -58,13 +58,41 @@ notify() {
     log "NOTIFY (telegram disabled — no token/chat): $text"
     return 0
   fi
-  curl -fsS --max-time "$CURL_TIMEOUT" \
-    -X POST "https://api.telegram.org/bot${TELEGRAM_BOT_TOKEN}/sendMessage" \
-    -d "chat_id=${TELEGRAM_CHAT_ID}" \
-    -d "disable_web_page_preview=true" \
-    --data-urlencode "text=${text}" \
-    >/dev/null 2>&1 \
-    || log "WARN: telegram sendMessage failed"
+  # #3059: путь до Telegram теряет соединения. Замер 26.08 с Poincare — 40
+  # подключений к ЗАКРЕПЛЁННОМУ (#3093) 149.154.167.220: 3 отказа (7.5%), все
+  # таймаутом на установке соединения; успешные при этом стабильны (0.14-0.17 с).
+  # Три остальных дата-центра Telegram с Selectel недостижимы вовсе, так что
+  # запасного адреса нет — потери на единственном рабочем неустранимы сетью.
+  #
+  # Раньше здесь был ОДИН curl, и `|| log WARN` означал, что каждый такой отказ
+  # ТЕРЯЕТ алерт целиком: уведомление о падении прода не приходит, остаётся
+  # строка в логе, который читают уже после аварии. Watchdog, который сам себя
+  # не может дозваться, — худший вид самоскрывающейся поломки: чем хуже дела,
+  # тем вероятнее, что о них не сообщат.
+  #
+  # Цикл, а не `curl --retry`: ниже в этом же файле проверки уже повторяются
+  # ровно такой конструкцией (см. `for attempt in $(seq 1 ...)`), и семантика
+  # `--max-time` при ретраях curl зависит от версии. Здесь таймаут заведомо
+  # применяется к КАЖДОЙ попытке.
+  #
+  # Дубль вместо потери — осознанный размен: sendMessage не идемпотентен, но
+  # замер показал, что отказы происходят на СТАДИИ ПОДКЛЮЧЕНИЯ, до отправки
+  # запроса, так что повтор почти никогда не дублирует уже доставленное
+  # сообщение. А продублированный алерт безвреден, пропущенный — нет.
+  local attempt
+  for attempt in 1 2 3; do
+    if curl -fsS --max-time "$CURL_TIMEOUT" \
+      -X POST "https://api.telegram.org/bot${TELEGRAM_BOT_TOKEN}/sendMessage" \
+      -d "chat_id=${TELEGRAM_CHAT_ID}" \
+      -d "disable_web_page_preview=true" \
+      --data-urlencode "text=${text}" \
+      >/dev/null 2>&1; then
+      [[ "$attempt" -gt 1 ]] && log "telegram sendMessage: доставлено с попытки ${attempt}"
+      return 0
+    fi
+    [[ "$attempt" -lt 3 ]] && sleep "${NOTIFY_RETRY_DELAY:-2}"
+  done
+  log "WARN: telegram sendMessage failed — 3 попытки подряд, алерт НЕ ДОСТАВЛЕН"
 }
 
 # --- state helpers (last status per check) ---