rippy/docker/worker/logbruecke.py

"""Celery-Ausgabe des Workers nach Rippy melden — statt in eine txt-Datei.

Commander-Wunsch 26.07.2026: *„bessere Log-Ansichten (kein txt file → direkt von
Rippy Logs)"*. Der native Windows-Worker schrieb sein Log bisher nach
`%LOCALAPPDATA%\\Rippy Worker\\worker.log`, und das Tray öffnete die Datei im
Editor. Wer wissen wollte, warum der Worker nichts tut, musste sich also an den
PC setzen — während Rippy im Browser schon eine Log-Seite hat.

## Was hier durchgeht — und warum so wenig

Die JOB-Meldungen stehen längst in Rippy: `tasks.py` schreibt „Kompression
gestartet", Fehlschläge, Abbrüche selbst über `db.add_log`. Was fehlte, ist
alles, was DANEBEN passiert und den Worker unbrauchbar macht, ohne dass ein Job
existiert:

- Der Worker ist hochgefahren (oder eben nicht).
- Die Verbindung zu Redis/Postgres steht nicht.
- Er ist abgestürzt (Traceback).

Alles andere wird verworfen. Celery ist bei `--loglevel=info` gesprächig, die
`logs`-Tabelle hat keine automatische Aufräumung, und ein zugemülltes Log ist
genauso unbrauchbar wie keins.

## Das Format ist gemessen, nicht geraten

Wörtlich aus dem laufenden Worker-Container (26.07.2026, Celery 5.4.0) —
AGENTS Regel D:

    [2026-07-26 12:04:18,060: INFO/MainProcess] Connected to redis://redis:6379/0
    [2026-07-26 12:04:19,063: INFO/MainProcess] mingle: searching for neighbors
    [2026-07-26 12:04:19,082: INFO/MainProcess] celery@ced31798928d ready.
    [2026-07-26 12:06:19,094: WARNING/MainProcess] Zombie-Erkennung: {...}

Dazu der Startbanner (Zeilen ohne diese Klammer) und Warnungen aus Pythons
warnings-Modul.
"""

import re

# `[<Zeitstempel>: <LEVEL>/<Prozess>] <Text>`
CELERY_ZEILE = re.compile(r"^\[[^\]]*?:\s*(\w+)/([^\]]+)\]\s*(.*)$")

# Celery-Level → Rippy-Level. DEBUG fällt bewusst weg.
LEVEL_MAP = {
    "CRITICAL": "error",
    "ERROR": "error",
    "WARNING": "warning",
    "INFO": "info",
}

# INFO-Zeilen sind nur interessant, wenn sie einen ZUSTAND melden. Diese Stücke
# sind alle oben im echten Log nachweisbar.
INFO_DURCHLASSEN = ("ready.", "Connected to", "Trying again", "connection")

# ... und diese sind reines Grundrauschen.
INFO_VERWERFEN = ("mingle:", "task events", "searching for neighbors", "all alone")

# Zeilen OHNE Celery-Klammer (Startbanner, Python-warnings) kommen nur durch,
# wenn sie nach einem echten Problem aussehen.
ROHE_FEHLER = ("Traceback", "Error:", "error(", "Errno", "refused", "Cannot")

# Schutz für die logs-Tabelle: mehr als das pro Minute ist kein Log, das ist ein
# Wasserfall.
MAX_ZEILEN_JE_MINUTE = 30


def einordnen(zeile: str):
    """(level, text) für eine Ausgabezeile — oder None, wenn sie nichts wert ist.

    Reine Funktion, damit das Urteil ohne laufenden Worker prüfbar ist.
    """
    text = (zeile or "").strip()
    if not text:
        return None
    treffer = CELERY_ZEILE.match(text)
    if not treffer:
        # Startbanner und warnings-Ausgaben: nur echte Probleme.
        if any(s in text for s in ROHE_FEHLER):
            return ("error", text[:500])
        return None
    celery_level, _prozess, inhalt = treffer.groups()
    level = LEVEL_MAP.get(celery_level.upper())
    if not level or not inhalt:
        return None
    if level == "info":
        if any(s in inhalt for s in INFO_VERWERFEN):
            return None
        if not any(s in inhalt for s in INFO_DURCHLASSEN):
            return None
        # „ready." heißt: der Worker nimmt jetzt Aufträge an. Das ist die
        # Meldung, auf die man wartet, wenn nichts passiert.
        if "ready." in inhalt:
            return ("success", inhalt[:500])
    return (level, inhalt[:500])


def quelle_fuer(worker_name: str) -> str:
    """Log-Quelle für diesen Worker.

    Gekappt auf 32 Zeichen, weil `logs.source` genau so breit ist (db.py). Ohne
    das Kappen scheitert das Insert still bei einem langen Worker-Namen — und
    dann fehlt genau das Log, das man sucht.
    """
    name = (worker_name or "worker").strip() or "worker"
    return f"w:{name}"[:32]


class Bruecke:
    """Nimmt Ausgabezeilen und schreibt die wichtigen nach Rippy.

    `schreiber(level, quelle, text)` und `jetzt()` sind einspritzbar — so ist
    die Drosselung ohne Datenbank und ohne echte Uhr prüfbar.
    """

    def __init__(self, worker_name: str, schreiber, jetzt):
        self.quelle = quelle_fuer(worker_name)
        self.schreiber = schreiber
        self.jetzt = jetzt
        self._fenster_start = None
        self._im_fenster = 0
        self._unterdrueckt = 0

    def zeile(self, text: str) -> bool:
        """Eine Ausgabezeile verarbeiten. True, wenn sie nach Rippy ging."""
        eingeordnet = einordnen(text)
        if not eingeordnet:
            return False
        level, inhalt = eingeordnet

        jetzt = self.jetzt()
        if self._fenster_start is None or jetzt - self._fenster_start >= 60:
            # Neues Fenster: erst melden, wieviel im alten verschluckt wurde.
            if self._unterdrueckt:
                self._melden(
                    "warning",
                    f"{self._unterdrueckt} weitere Log-Zeilen unterdrückt "
                    "(mehr als 30 pro Minute) — Details im Worker-Log auf der "
                    "Maschine selbst.",
                )
            self._fenster_start = jetzt
            self._im_fenster = 0
            self._unterdrueckt = 0

        if self._im_fenster >= MAX_ZEILEN_JE_MINUTE:
            self._unterdrueckt += 1
            return False
        self._im_fenster += 1
        return self._melden(level, inhalt)

    def _melden(self, level: str, text: str) -> bool:
        try:
            self.schreiber(level, self.quelle, text)
            return True
        except Exception:
            # Rippy nicht erreichbar → die lokale Datei bleibt der Rückfall.
            # Hier NICHTS werfen: der Worker soll weiterarbeiten.
            return False