396 lines
17 KiB
Python
396 lines
17 KiB
Python
"""Сторож собственных прогонов: журнал `job_runs` наконец кто-то читает.
|
||
|
||
Планировщик gateway пишет строку на каждый прогон джоба (`job_runs`: имя,
|
||
статус, хвост трейсбека в `error`). Запись была всегда, читателя не было
|
||
ни одного: канал к соседнему агенту лежал 38 часов подряд, планировщик
|
||
честно записал это 231 раз, и до человека не доехало ничего. Этот модуль -
|
||
вторая половина прибора: показание из таблицы превращается в тревогу.
|
||
|
||
Что здесь считается показанием:
|
||
|
||
- тревога берётся только с ХВОСТА: три и более `failed` подряд, считая от
|
||
последнего прогона джоба. Одиночный упавший прогон - сетевой чих, а не
|
||
болезнь, и будить на него человека значит выучить его не смотреть;
|
||
- пустая выдача - это показание о запросе, а не о здоровье джобов. Ноль
|
||
строк за сутки (кроме своих) означает, что планировщик вообще не
|
||
работал, и это отдельная тревога с отдельным текстом, а не тишина;
|
||
- упавший запрос к БД - не показание вовсе: решает джоб, здесь такого
|
||
входа просто нет.
|
||
|
||
Свои собственные прогоны из счёта выкинуты (`me`): джоб, который лежит,
|
||
о себе не доложит - наблюдатель внутри объекта не сообщает о смерти
|
||
объекта. Это дыра прибора, и она названа в README, а не заклеена.
|
||
|
||
Текст тревоги проходит `mask`: из `error` берётся первая строка, режется
|
||
по длине и чистится - общим `redact` gateway плюс два своих правила на то,
|
||
что `redact` по конструкции не ловит внутри строки (`ИМЯ=значение` не с
|
||
начала строки и хвост запроса у URL). Тревога уезжает в чат к диспетчеру,
|
||
логи гейтвея видны в чатах - секрету тут негде быть.
|
||
"""
|
||
|
||
from __future__ import annotations
|
||
|
||
import itertools
|
||
import json
|
||
import re
|
||
from dataclasses import dataclass, field
|
||
from datetime import UTC, datetime, timedelta
|
||
from pathlib import Path # noqa: TC003 - в аннотации dataclass
|
||
from typing import TYPE_CHECKING
|
||
|
||
from beaver_gateway.security.redact import MASK, is_secret_name, redact
|
||
|
||
if TYPE_CHECKING:
|
||
from collections.abc import Sequence
|
||
|
||
__all__ = [
|
||
"ERROR_CHARS",
|
||
"FAILED",
|
||
"FORGET",
|
||
"MAX_LINES",
|
||
"REPEAT",
|
||
"STREAK",
|
||
"WINDOW",
|
||
"Clear",
|
||
"Report",
|
||
"Run",
|
||
"Runs",
|
||
"Streak",
|
||
"alarm_text",
|
||
"clear_text",
|
||
"empty_text",
|
||
"first_line",
|
||
"look",
|
||
"mask",
|
||
"streak",
|
||
]
|
||
|
||
WINDOW = timedelta(hours=24)
|
||
"""Окно журнала: сутки. Джоб реже трёх раз в сутки за него не наберёт серии
|
||
из трёх падений - это слепая зона, названная в README."""
|
||
STREAK = 3
|
||
"""Сколько `failed` подряд считаем «джоб лежит»."""
|
||
REPEAT = timedelta(hours=24)
|
||
"""Чаще этого об одном и том же джобе не говорим."""
|
||
FORGET = timedelta(days=7)
|
||
"""Джоб, о котором тревожились, исчез из окна насовсем - забываем его молча:
|
||
починки мы не видели, врать «отбой» не о чем."""
|
||
ERROR_CHARS = 160
|
||
"""Сколько букв первой строки ошибки уезжает человеку."""
|
||
MAX_LINES = 10
|
||
"""Сколько джобов перечисляем в одной тревоге: сразу всё не читают."""
|
||
FAILED = "failed"
|
||
STATE_VERSION = 1
|
||
|
||
_PAIR = re.compile(r"(?=([A-Za-z][\w.-]{2,})\s*([:=])\s*([^\s,;)\]}\"']{6,}))")
|
||
"""`ИМЯ=значение` где угодно в строке: общий `redact` ловит такие пары только
|
||
с начала строки, а трейсбек кладёт их в середину. Просмотр нулевой длины -
|
||
чтобы `RuntimeError: MSOS_MCP=…` не съедало секрет первой же парой: обычный
|
||
`sub` откусил бы `RuntimeError:` вместе со значением и до вложенной пары
|
||
не дошёл."""
|
||
_QUERY = re.compile(r"(https?://[^\s?#]+)\?[^\s#]*")
|
||
"""Хвост запроса у URL сносим целиком: имя параметра с ключом может быть любым."""
|
||
|
||
|
||
def _iso(when: datetime | None) -> str | None:
|
||
if when is None:
|
||
return None
|
||
return when.astimezone(UTC).strftime("%Y-%m-%dT%H:%M:%SZ")
|
||
|
||
|
||
def _parse_iso(raw: str | None) -> datetime | None:
|
||
if not raw:
|
||
return None
|
||
try:
|
||
when = datetime.fromisoformat(raw)
|
||
except ValueError:
|
||
return None
|
||
return when if when.tzinfo else when.replace(tzinfo=UTC)
|
||
|
||
|
||
def _plural(count: int, forms: tuple[str, str, str]) -> str:
|
||
if count % 10 == 1 and count % 100 != 11:
|
||
return forms[0]
|
||
if count % 10 in (2, 3, 4) and count % 100 not in (12, 13, 14):
|
||
return forms[1]
|
||
return forms[2]
|
||
|
||
|
||
def _age(delta: timedelta) -> str:
|
||
"""Возраст человеку: «4 часа», «45 минут». Секунды тут не нужны никому."""
|
||
minutes = max(int(delta.total_seconds()) // 60, 0)
|
||
if minutes < 60:
|
||
return f"{minutes} {_plural(minutes, ('минуту', 'минуты', 'минут'))}"
|
||
hours = minutes // 60
|
||
return f"{hours} {_plural(hours, ('час', 'часа', 'часов'))}"
|
||
|
||
|
||
def _mask_pairs(text: str) -> str:
|
||
out: list[str] = []
|
||
pos = 0
|
||
for match in _PAIR.finditer(text):
|
||
if match.start(3) < pos or not is_secret_name(match[1]):
|
||
continue
|
||
out.append(text[pos : match.start(3)])
|
||
out.append(MASK)
|
||
pos = match.end(3)
|
||
out.append(text[pos:])
|
||
return "".join(out)
|
||
|
||
|
||
def mask(text: str) -> str:
|
||
"""Убрать из строки всё, что похоже на секрет, прежде чем её показывать."""
|
||
return _QUERY.sub(r"\1?" + MASK, _mask_pairs(redact(text)))
|
||
|
||
|
||
def first_line(error: str | None) -> str:
|
||
"""Первая строка ошибки - чистая и короткая. Трейсбек человеку не нужен."""
|
||
for line in mask(error or "").splitlines():
|
||
head = line.strip()
|
||
if not head:
|
||
continue
|
||
if len(head) > ERROR_CHARS:
|
||
head = head[: ERROR_CHARS - 1].rstrip() + "…"
|
||
return head
|
||
return "без текста ошибки"
|
||
|
||
|
||
@dataclass(frozen=True, slots=True)
|
||
class Run:
|
||
"""Одна строка журнала: ровно то, на что мы смотрим, без ORM."""
|
||
|
||
id: int
|
||
job: str
|
||
status: str
|
||
started_at: datetime
|
||
error: str | None = None
|
||
|
||
@property
|
||
def failed(self) -> bool:
|
||
return self.status == FAILED
|
||
|
||
|
||
@dataclass(frozen=True, slots=True)
|
||
class Streak:
|
||
"""Хвост подряд упавших прогонов одного джоба."""
|
||
|
||
job: str
|
||
count: int
|
||
since: datetime
|
||
"""Начало серии - первое падение из тех, что видно в окне."""
|
||
age: timedelta
|
||
error: str
|
||
capped: bool
|
||
"""Серия упёрлась в край окна: падений было НЕ МЕНЬШЕ `count`, а сколько
|
||
на самом деле - за сутками не видно, и врать точным числом нельзя."""
|
||
|
||
|
||
@dataclass(frozen=True, slots=True)
|
||
class Clear:
|
||
"""Джоб, о котором мы тревожились, больше не лежит."""
|
||
|
||
job: str
|
||
status: str
|
||
"""Статус последнего прогона."""
|
||
count: int
|
||
"""Сколько подряд упавших осталось в хвосте: 0 - чисто."""
|
||
|
||
|
||
@dataclass(slots=True)
|
||
class Runs:
|
||
"""Состояние между прогонами: кому и когда уже сказали."""
|
||
|
||
path: Path
|
||
alerted: dict[str, datetime] = field(default_factory=dict)
|
||
"""Джоб → когда о нём ушла тревога. Он же признак «сейчас в тревоге»."""
|
||
empty_alerted: datetime | None = None
|
||
|
||
@classmethod
|
||
def load(cls, path: Path) -> Runs:
|
||
try:
|
||
raw = json.loads(path.read_text(encoding="utf-8"))
|
||
except (OSError, ValueError):
|
||
return cls(path=path)
|
||
if raw.get("version") != STATE_VERSION:
|
||
return cls(path=path)
|
||
alerted = {}
|
||
for job, when in dict(raw.get("alerted") or {}).items():
|
||
parsed = _parse_iso(str(when))
|
||
if parsed is not None:
|
||
alerted[str(job)] = parsed
|
||
return cls(
|
||
path=path,
|
||
alerted=alerted,
|
||
empty_alerted=_parse_iso(raw.get("empty_alerted")),
|
||
)
|
||
|
||
def save(self) -> None:
|
||
body = {
|
||
"version": STATE_VERSION,
|
||
"alerted": {job: _iso(when) for job, when in sorted(self.alerted.items())},
|
||
"empty_alerted": _iso(self.empty_alerted),
|
||
}
|
||
self.path.parent.mkdir(parents=True, exist_ok=True)
|
||
tmp = self.path.with_suffix(".tmp")
|
||
tmp.write_text(json.dumps(body, ensure_ascii=False, indent=1), encoding="utf-8")
|
||
tmp.replace(self.path)
|
||
|
||
|
||
@dataclass(frozen=True, slots=True)
|
||
class Report:
|
||
"""Что решил один прогон сторожа журнала."""
|
||
|
||
alarms: tuple[Streak, ...]
|
||
clears: tuple[Clear, ...]
|
||
empty: bool
|
||
"""Прогонов за сутки не было вовсе - тревога о планировщике, не о джобе."""
|
||
seen: int
|
||
"""Сколько чужих прогонов было в окне."""
|
||
mine: int
|
||
"""Сколько своих - их в счёт не берём, но в тексте называем."""
|
||
note: str
|
||
|
||
|
||
def streak(runs: Sequence[Run], *, now: datetime) -> Streak | None:
|
||
"""Хвост падений одного джоба, считая от последнего прогона.
|
||
|
||
`runs` - прогоны одного джоба, новейший первым. Серия, упёршаяся в край
|
||
окна, помечается `capped`: её настоящую длину мы не знаем.
|
||
"""
|
||
failures = list(itertools.takewhile(lambda run: run.failed, runs))
|
||
if not failures:
|
||
return None
|
||
oldest = failures[-1]
|
||
return Streak(
|
||
job=failures[0].job,
|
||
count=len(failures),
|
||
since=oldest.started_at,
|
||
age=now - oldest.started_at,
|
||
error=first_line(failures[0].error),
|
||
capped=len(failures) == len(runs),
|
||
)
|
||
|
||
|
||
def look(state: Runs, runs: Sequence[Run], *, now: datetime, me: str) -> Report:
|
||
"""Разобрать окно журнала и решить, о чём говорить человеку.
|
||
|
||
Состояние здесь только чистится от забытых джобов; отметки «сказали» и
|
||
«сказали про пустоту» ставит джоб - и только когда тревога действительно
|
||
ушла: несостоявшаяся доставка не должна заглушать следующий прогон.
|
||
"""
|
||
mine = sum(1 for run in runs if run.job == me)
|
||
others = sorted(
|
||
(run for run in runs if run.job != me), key=lambda run: run.id, reverse=True
|
||
)
|
||
if not others:
|
||
quiet = state.empty_alerted is not None and now - state.empty_alerted < REPEAT
|
||
return Report(
|
||
alarms=(),
|
||
clears=(),
|
||
empty=not quiet,
|
||
seen=0,
|
||
mine=mine,
|
||
note=(
|
||
f"чужих прогонов за сутки нет вовсе (своих {mine})"
|
||
+ ("; о пустоте уже говорили меньше суток назад" if quiet else "")
|
||
),
|
||
)
|
||
|
||
by_job: dict[str, list[Run]] = {}
|
||
for run in others:
|
||
by_job.setdefault(run.job, []).append(run)
|
||
|
||
alarms: list[Streak] = []
|
||
clears: list[Clear] = []
|
||
held: list[str] = []
|
||
for job, rows in by_job.items():
|
||
tail = streak(rows, now=now)
|
||
if tail is not None and tail.count >= STREAK:
|
||
told = state.alerted.get(job)
|
||
if told is None or now - told >= REPEAT:
|
||
alarms.append(tail)
|
||
else:
|
||
held.append(job)
|
||
elif job in state.alerted:
|
||
clears.append(
|
||
Clear(
|
||
job=job,
|
||
status=rows[0].status,
|
||
count=0 if tail is None else tail.count,
|
||
)
|
||
)
|
||
|
||
forgotten = [
|
||
job
|
||
for job, told in state.alerted.items()
|
||
if job not in by_job and now - told >= FORGET
|
||
]
|
||
for job in forgotten:
|
||
del state.alerted[job]
|
||
|
||
note = f"прогонов за сутки {len(others)} по {len(by_job)} джобам (своих {mine})"
|
||
if alarms:
|
||
note += "; лежат: " + ", ".join(sorted(tail.job for tail in alarms))
|
||
if held:
|
||
note += "; уже говорили меньше суток назад: " + ", ".join(sorted(held))
|
||
if clears:
|
||
note += "; починились: " + ", ".join(sorted(clear.job for clear in clears))
|
||
if forgotten:
|
||
note += "; забыты (пропали из окна): " + ", ".join(sorted(forgotten))
|
||
|
||
return Report(
|
||
alarms=tuple(sorted(alarms, key=lambda tail: tail.count, reverse=True)),
|
||
clears=tuple(sorted(clears, key=lambda clear: clear.job)),
|
||
empty=False,
|
||
seen=len(others),
|
||
mine=mine,
|
||
note=note,
|
||
)
|
||
|
||
|
||
def streak_line(tail: Streak) -> str:
|
||
"""«джоб `вайбграм` лежит 4 часа, 24 прогона подряд с 12.09 18:00 UTC: …»."""
|
||
runs = f"{tail.count} {_plural(tail.count, ('прогон', 'прогона', 'прогонов'))}"
|
||
return (
|
||
f"джоб `{tail.job}` лежит {_age(tail.age)}"
|
||
f"{' и дольше' if tail.capped else ''}, {runs} подряд с "
|
||
f"{tail.since.astimezone(UTC).strftime('%d.%m %H:%M UTC')}"
|
||
+ (" (это всё окно суток, серия началась раньше)" if tail.capped else "")
|
||
+ f": {tail.error}"
|
||
)
|
||
|
||
|
||
def alarm_text(report: Report) -> str:
|
||
"""Тревога человеку: что лежит, сколько и с какой ошибкой."""
|
||
lines = [f"- {streak_line(tail)}" for tail in report.alarms[:MAX_LINES]]
|
||
rest = len(report.alarms) - len(lines)
|
||
if rest > 0:
|
||
lines.append(f"- и ещё {rest} {_plural(rest, ('джоб', 'джоба', 'джобов'))}")
|
||
return "\n".join(lines)
|
||
|
||
|
||
def clear_line(clear: Clear) -> str:
|
||
if clear.count == 0:
|
||
return f"отбой: джоб `{clear.job}` снова проходит ({clear.status})"
|
||
return (
|
||
f"отбой: джоб `{clear.job}` больше не лежит подряд "
|
||
f"(упавших в хвосте {clear.count}, порог {STREAK})"
|
||
)
|
||
|
||
|
||
def clear_text(report: Report) -> str:
|
||
return "\n".join(f"- {clear_line(clear)}" for clear in report.clears)
|
||
|
||
|
||
def empty_text(report: Report) -> str:
|
||
"""Отдельная тревога: за сутки не отработал вообще никто."""
|
||
return (
|
||
f"За последние сутки в журнале прогонов (`job_runs`) нет ни одной записи, "
|
||
f"кроме моих собственных (их {report.mine}): не отработал ни один джоб. "
|
||
"Это показание о планировщике, а не о каком-то одном джобе. Смотреть "
|
||
"стоит три вещи: поднялся ли планировщик вообще (в логе gateway "
|
||
"`scheduler: no postgres driver - cron and webhooks are off`), живы ли "
|
||
"кроны в pgqueuer, и не заведена ли база заново - на пустой базе эта же "
|
||
"тревога выглядит так же."
|
||
)
|