FabledSteward/plugins/syslog/patterns.py

# plugins/syslog/patterns.py
"""Telling phrases in the kept lines, counted per source into the metric
store every minute (#6001), so an ordinary alert rule can watch them.

A pattern's sample is the number of a source's lines that matched in the last
`window_minutes`, written for every added source it covers, zero included:
a rule "> 0" fires on the first match and clears once the window has passed
it, rather than holding the last count forever.

Phrases are plain text matched case-insensitively anywhere in the message,
not regular expressions: they read the same in the form, the page and the
query, and a phrase someone types can't make the count slow.
"""
from __future__ import annotations

import asyncio
import logging
import re
from collections import Counter
from dataclasses import dataclass, field
from datetime import datetime, timedelta, timezone
from typing import TYPE_CHECKING

from sqlalchemy import func, or_, select

from steward.core.like import escape_like
from steward.core.scheduler import ScheduledTask

from .models import SyslogLine, SyslogPattern, SyslogSource, metric_for

if TYPE_CHECKING:
    from quart import Quart

logger = logging.getLogger(__name__)

SOURCE_MODULE = "syslog"
COUNT_S = 60
# The count's own deadline: past it the minute is skipped, not stacked.
COUNT_DEADLINE_S = 45.0
WINDOWS = (5, 15, 60, 240, 1440)
MAX_PHRASES = 20


@dataclass(frozen=True)
class Preset:
    key: str
    name: str
    phrases: tuple[str, ...] = ()
    max_severity: int | None = None
    about: str = ""


# Storage trouble as NAS and Linux kernels word it, and errors of any kind.
PRESETS: tuple[Preset, ...] = (
    Preset("io_error", "Disk I/O errors",
           ("I/O error", "blk_update_request", "medium error", "end_request:"),
           about="A disk or its controller failed a read or write."),
    Preset("disk_reset", "Disk resets and timeouts",
           ("hard resetting link", "SATA link down", "exception Emask", "link is slow to respond",
            "device reset"),
           about="A disk stopped answering and the kernel reset its link."),
    Preset("nfs", "NFS server trouble",
           ("nfsd:", "nfs: server", "not responding, still trying", "lockd:"),
           about="The NFS server or its lock manager complained."),
    Preset("fs_error", "Filesystem errors",
           ("EXT4-fs error", "BTRFS error", "BTRFS critical", "XFS: ", "Remounting filesystem read-only",
            "csum failed"),
           about="A filesystem found damage or went read-only."),
    Preset("raid", "RAID or storage pool degraded",
           ("degraded", "Disk failure on", "crashed", "faulty"),
           about="An array lost a disk, or a storage pool crashed."),
    Preset("errors", "Errors and worse", max_severity=3,
           about="Any line the device marked err, crit, alert or emerg."),
)
PRESETS_BY_KEY = {p.key: p for p in PRESETS}


class PatternError(ValueError):
    pass


_KEY = re.compile(r"[^a-z0-9]+")


def key_for(name: str) -> str:
    """A pattern's metric key from its name: "Disk I/O errors" → "disk_i_o_errors"."""
    return _KEY.sub("_", name.lower()).strip("_")[:48] or "pattern"


def parse_form(form) -> dict:
    """A pattern's fields from its form, or PatternError saying what to fix."""
    name = (form.get("name") or "").strip()[:100]
    if not name:
        raise PatternError("Give the pattern a name.")
    phrases = [p.strip() for p in (form.get("phrases") or "").splitlines() if p.strip()]
    if len(phrases) > MAX_PHRASES:
        raise PatternError(f"At most {MAX_PHRASES} phrases.")
    if any(len(p) > 200 for p in phrases):
        raise PatternError("A phrase can be at most 200 characters.")
    severity = (form.get("max_severity") or "").strip()
    max_severity = int(severity) if severity.isdigit() and int(severity) <= 7 else None
    if not phrases and max_severity is None:
        raise PatternError("Give at least one phrase, or a severity to count.")
    try:
        window = int(form.get("window_minutes") or 15)
    except ValueError:
        window = 15
    if window not in WINDOWS:
        window = 15
    return {"name": name, "phrases": phrases, "max_severity": max_severity,
            "source_id": form.get("source_id") or None, "window_minutes": window,
            "enabled": "enabled" in form}


def matches(pattern, severity: int, message: str) -> bool:
    """Whether one line matches: the same test the count's query makes."""
    if pattern.max_severity is not None and severity > pattern.max_severity:
        return False
    text = message.lower()
    return not pattern.phrases or any(p.lower() in text for p in pattern.phrases)


def resource_of(source: SyslogSource) -> str:
    """A source's name in the metric store."""
    return source.name or source.hostname_seen or source.address


def _match_query(p, source_ids: list[str]):
    """The lines a pattern matches among these sources: the same test as matches()."""
    stmt = select(SyslogLine.id, SyslogLine.source_id, SyslogLine.received_at).where(
        SyslogLine.source_id.in_(source_ids))
    if p.max_severity is not None:
        stmt = stmt.where(SyslogLine.severity <= p.max_severity)
    if p.phrases:
        stmt = stmt.where(or_(*(SyslogLine.message.ilike(f"%{escape_like(ph)}%", escape="\\")
                                for ph in p.phrases)))
    return stmt


def _minute(at: datetime) -> datetime:
    return at.replace(second=0, microsecond=0)


@dataclass
class Tally:
    """A pattern's matches per source per minute, kept between counts so each
    count reads only the lines stored since the last one, not its whole window."""
    sig: tuple
    minutes: dict[str, Counter] = field(default_factory=dict)

    def add(self, source_id: str, received_at: datetime) -> None:
        self.minutes.setdefault(source_id, Counter())[_minute(received_at)] += 1

    def count(self, source_id: str, since: datetime) -> int:
        """Matches from `since`'s minute on; minutes before it are dropped."""
        per = self.minutes.get(source_id)
        if not per:
            return 0
        start = _minute(since)
        for m in [m for m in per if m < start]:
            del per[m]
        return sum(per.values())


@dataclass
class Tallies:
    """Every pattern's tally, and the newest line id they have all counted.
    Line ids are time-ordered and given as a line is stored, by the one
    receiver, so lines stored later always have higher ids: a line held
    through a database outage is still counted when it lands, in the minute
    it was received."""
    upto: str | None = None
    by_pattern: dict[str, Tally] = field(default_factory=dict)


TALLIES = Tallies()


def _sig(p) -> tuple:
    return (tuple(p.phrases or ()), p.max_severity, p.source_id, p.window_minutes)


async def count_matches(session, patterns: list, sources: list, now: datetime,
                        tallies: Tallies | None = None) -> list[tuple[str, str, int]]:
    """(resource, metric, lines matched in the pattern's window) for every
    enabled pattern and every added source it covers, zero included.

    A pattern new or changed since the last count reads its window once;
    after that, each count reads only the lines stored since the one before."""
    tallies = TALLIES if tallies is None else tallies
    try:
        return await _count(session, patterns, sources, now, tallies)
    except BaseException:
        # Cut short (the count's deadline, a lost connection): some tallies
        # may hold lines the cursor doesn't yet cover, so start them over.
        tallies.upto, tallies.by_pattern = None, {}
        raise


async def _count(session, patterns: list, sources: list, now: datetime, tallies: Tallies) -> list:
    newest = (await session.execute(select(func.max(SyslogLine.id)))).scalar()
    out = []
    live = set()
    for p in patterns:
        if not p.enabled:
            continue
        live.add(p.id)
        covered = [s for s in sources if s.state == "accepted" and p.source_id in (None, s.id)]
        if not covered:
            continue
        since = now - timedelta(minutes=p.window_minutes)
        tally = tallies.by_pattern.get(p.id)
        stmt = _match_query(p, [s.id for s in covered])
        if tally is None or tally.sig != _sig(p) or tallies.upto is None:
            tally = tallies.by_pattern[p.id] = Tally(_sig(p))
            stmt = stmt.where(SyslogLine.received_at >= since)
        else:
            stmt = stmt.where(SyslogLine.id > tallies.upto)
        if newest is not None:
            stmt = stmt.where(SyslogLine.id <= newest)
            for _, source_id, received_at in (await session.execute(stmt)).all():
                tally.add(source_id, received_at)
        out.extend((resource_of(s), metric_for(p.key), tally.count(s.id, since)) for s in covered)
    for gone in set(tallies.by_pattern) - live:
        del tallies.by_pattern[gone]
    if newest is not None:
        tallies.upto = newest
    return out


def make_count_task(app: "Quart") -> ScheduledTask:
    async def count() -> None:
        try:
            await asyncio.wait_for(record_counts(app), COUNT_DEADLINE_S)
        except TimeoutError:
            logger.warning("Syslog: counting pattern matches took over %.0f s; this minute is skipped",
                           COUNT_DEADLINE_S)

    return ScheduledTask(name="syslog_pattern_counts", coro_factory=count, interval_seconds=COUNT_S)


async def record_counts(app: "Quart", now: datetime | None = None) -> int:
    """Count every pattern's matches and record them as metrics, so the alert
    rules watching them are evaluated. Returns how many samples it wrote."""
    from steward.core.alerts import MetricBatch

    now = now or datetime.now(timezone.utc)
    async with app.db_sessionmaker() as session:
        async with session.begin():
            patterns = list((await session.execute(
                select(SyslogPattern).where(SyslogPattern.enabled.is_(True)))).scalars())
            if not patterns:
                return 0
            sources = list((await session.execute(
                select(SyslogSource).where(SyslogSource.state == "accepted"))).scalars())
            samples = await count_matches(session, patterns, sources, now)
            batch = MetricBatch()
            for resource, metric, value in samples:
                batch.add(source_module=SOURCE_MODULE, resource_name=resource, metric_name=metric,
                          value=float(value), recorded_at=now)
            await batch.record(session)
    return len(samples)